Add configurable verbosity and guarded shell tracing

__tests__/utils.test.ts

@@ -1,4 +1,6 @@
 import fs from 'fs';
+import os from 'os';
+import {spawnSync} from 'child_process';
 import * as path from 'path';
 import * as utils from '../src/utils';
 import * as fetchModule from '../src/fetch';
@@ -395,3 +397,437 @@ describe('Utils tests', () => {
     expect(script).toEqual('\n$var = command\n');
   });
 });
+
+const hasPwsh =
+  spawnSync('pwsh', ['-NoProfile', '-Command', 'exit 0']).status === 0;
+const scripts = path.join(__dirname, '../src/scripts');
+const unixInit = fs.readFileSync(path.join(scripts, 'unix.sh'), 'utf8');
+const windowsSource = fs.readFileSync(path.join(scripts, 'win32.ps1'), 'utf8');
+const windowsInit = [
+  windowsSource.match(/Function Invoke-WithoutTrace[\s\S]*?\n}/)![0],
+  windowsSource.match(
+    /\$setup_php_trace = 0\r?\nif \(\$env:SETUP_PHP_TRACE[\s\S]*?\n}/
+  )![0]
+].join('\n');
+
+describe.each(['linux', 'darwin', 'win32'])(
+  'Verbose scripts on %s',
+  platform => {
+    let root: string;
+    let run: string;
+    let helper: string;
+    const env = {...process.env};
+
+    beforeEach(() => {
+      jest.restoreAllMocks();
+      root = fs.mkdtempSync(path.join(os.tmpdir(), 'setup-php-verbose-'));
+      const scripts = path.join(root, 'src', 'scripts');
+      const extension = platform === 'win32' ? '.ps1' : '.sh';
+      fs.mkdirSync(path.join(scripts, 'tools'), {recursive: true});
+      const init = path.join(scripts, 'init' + extension);
+      fs.writeFileSync(
+        init,
+        platform === 'win32'
+          ? windowsInit
+          : unixInit + '\nrunner=self-hosted read_env\n'
+      );
+      helper = path.join(scripts, 'tools', 'helper' + extension);
+      run = path.join(scripts, 'run' + extension);
+      fs.writeFileSync(helper, 'echo helper-output\n');
+      fs.writeFileSync(
+        run,
+        `. '${init}'\n. '${helper}' ${platform === 'win32' ? '>$null' : '>/dev/null'} 2>&1\n`
+      );
+      delete process.env.verbose;
+      delete process.env.VERBOSE;
+      delete process.env.RUNNER_DEBUG;
+    });
+
+    afterEach(() => {
+      process.env = {...env};
+      fs.rmSync(root, {recursive: true, force: true});
+    });
+
+    it.each([undefined, '', 'false', 'true', 'v', 'vv', 'vvv', 'invalid'])(
+      'prepares scripts for verbose=%s',
+      async verbose => {
+        if (verbose !== undefined) process.env.verbose = verbose;
+        const original = fs.readFileSync(run, 'utf8');
+        const enabled = /^(true|v{1,3})$/.test(verbose || '');
+        const tracing = /^v{2,3}$/.test(verbose || '');
+        const prepared = await utils.addVerbose(run, platform);
+        const script = fs.readFileSync(prepared, 'utf8');
+        expect(prepared !== run).toBe(enabled);
+        expect(script.includes('2>&1')).toBe(!enabled);
+        expect(script.includes('src-verbose')).toBe(enabled);
+        expect(script.startsWith('. ')).toBe(true);
+        expect(process.env.SETUP_PHP_TRACE).toBe(
+          tracing ? String(verbose!.length - 1) : '0'
+        );
+        expect(fs.readFileSync(run, 'utf8')).toBe(original);
+        if (platform === 'win32' ? hasPwsh : process.platform !== 'win32') {
+          const result = spawnSync(
+            platform === 'win32' ? 'pwsh' : 'bash',
+            platform === 'win32'
+              ? ['-NoProfile', '-File', prepared]
+              : [prepared],
+            {encoding: 'utf8', env: process.env}
+          );
+          expect(result.status).toBe(0);
+          expect(/helper-output\r?\n/.test(result.stdout)).toBe(enabled);
+          expect(
+            platform === 'win32'
+              ? result.stdout.includes('DEBUG:')
+              : result.stderr.includes('+ ')
+          ).toBe(tracing);
+        }
+      }
+    );
+
+    it.each(['', ' ', '\t'])(
+      'handles pipe spacing %j and subsequent quiet runs',
+      async space => {
+        const target = platform === 'win32' ? '$null' : '/dev/null';
+        const pipe = `>${space}${target} 2>&1`;
+        const probe =
+          platform === 'win32'
+            ? 'echo probe 2>$null'
+            : 'command -v sh >/dev/null';
+        fs.writeFileSync(helper, `echo nested-output ${pipe}\n${probe}\n`);
+        process.env.VERBOSE = 'true';
+        const prepared = await utils.addVerbose(run, platform);
+        expect(
+          fs.readFileSync(
+            path.join(path.dirname(prepared), 'tools', path.basename(helper)),
+            'utf8'
+          )
+        ).toBe(`echo nested-output \n${probe}\n`);
+        expect(fs.readFileSync(helper, 'utf8')).toContain(pipe);
+        const shell = platform === 'win32' ? 'pwsh' : 'bash';
+        if (platform === 'win32' ? hasPwsh : process.platform !== 'win32') {
+          const result = spawnSync(
+            shell,
+            platform === 'win32'
+              ? ['-NoProfile', '-File', prepared]
+              : [prepared],
+            {encoding: 'utf8', env: process.env}
+          );
+          expect(result.status).toBe(0);
+          expect(result.stdout).toMatch(/nested-output\r?\n/);
+        }
+        process.env.verbose = 'false';
+        expect(await utils.addVerbose(run, platform)).toBe(run);
+        expect(process.env.SETUP_PHP_TRACE).toBe('0');
+        expect(fs.readFileSync(helper, 'utf8')).toContain(pipe);
+      }
+    );
+
+    it.each([undefined, 'false', 'true', 'v', 'vv', 'vvv'])(
+      'enables output for runner debug with verbose=%s',
+      async verbose => {
+        process.env.RUNNER_DEBUG = '1';
+        if (verbose !== undefined) process.env.verbose = verbose;
+        const prepared = await utils.addVerbose(run, platform);
+        expect(prepared).not.toBe(run);
+        expect(fs.readFileSync(prepared, 'utf8')).not.toContain('2>&1');
+        expect(process.env.SETUP_PHP_TRACE).toBe(
+          /^v{2,3}$/.test(verbose || '') ? String(verbose!.length - 1) : '0'
+        );
+      }
+    );
+
+    it.each(['true', 'vv', 'vvv'])(
+      'protects nested sensitive calls and restores tracing for verbose=%s',
+      async verbose => {
+        const windows = platform === 'win32';
+        if (windows ? !hasPwsh : process.platform === 'win32') return;
+        process.env.verbose = verbose;
+        process.env.GITHUB_TOKEN = 'example-github-token';
+        process.env.TRACE_TEST_OUTPUT = path.join(root, 'tokens');
+        fs.writeFileSync(
+          helper,
+          windows
+            ? `$result = 0
+try {
+  Invoke-WithoutTrace {
+    Invoke-WithoutTrace {
+      $token = $env:GITHUB_TOKEN
+      Set-Content $env:TRACE_TEST_OUTPUT $token
+    }
+    $token = $env:GITHUB_TOKEN
+    Add-Content $env:TRACE_TEST_OUTPUT $token
+    if ($env:TRACE_TEST_STATUS -ne '0') { throw 'example-failure' }
+  }
+} catch {
+  if ($_.Exception.Message -ne 'example-failure') { throw }
+  $result = [int]$env:TRACE_TEST_STATUS
+}
+$after_wrapper = 'after-wrapper'
+Write-Output $after_wrapper
+Write-Output "status=$result"
+`
+            : `inner_sensitive() {
+  token="$GITHUB_TOKEN"
+  printf '%s\\n' "$token" > "$TRACE_TEST_OUTPUT"
+  return "$TRACE_TEST_STATUS"
+}
+outer_sensitive() {
+  without_trace inner_sensitive
+  local result=$?
+  token="$GITHUB_TOKEN"
+  printf '%s\\n' "$token" >> "$TRACE_TEST_OUTPUT"
+  return "$result"
+}
+without_trace outer_sensitive
+result=$?
+echo "\${token:+state-preserved}"
+echo after-wrapper
+exit "$result"
+`
+        );
+        const prepared = await utils.addVerbose(run, platform);
+        for (const status of [0, 37]) {
+          const result = spawnSync(
+            windows ? 'pwsh' : 'bash',
+            windows ? ['-NoProfile', '-File', prepared] : [prepared],
+            {
+              encoding: 'utf8',
+              env: {...process.env, TRACE_TEST_STATUS: String(status)}
+            }
+          );
+          expect(result.status).toBe(windows ? 0 : status);
+          expect(result.stdout + result.stderr).not.toContain(
+            'example-github-token'
+          );
+          expect(result.stdout).toContain('after-wrapper');
+          expect(
+            windows
+              ? /DEBUG:.*Write-Output \$after_wrapper/.test(result.stdout)
+              : result.stderr.includes('+ echo after-wrapper')
+          ).toBe(verbose !== 'true');
+          if (windows) {
+            expect(result.stdout).toContain('status=' + status);
+            expect(/DEBUG:\s+!\s+SET \$after_wrapper/.test(result.stdout)).toBe(
+              verbose === 'vvv'
+            );
+          } else {
+            expect(result.stdout).toContain('state-preserved');
+          }
+          expect(
+            fs
+              .readFileSync(process.env.TRACE_TEST_OUTPUT!, 'utf8')
+              .trim()
+              .split(/\r?\n/)
+          ).toEqual(['example-github-token', 'example-github-token']);
+        }
+      }
+    );
+
+    it.each(['true', 'vv', 'vvv'])(
+      'keeps Blackfire credentials out of traces for verbose=%s',
+      async verbose => {
+        const windows = platform === 'win32';
+        if (windows ? !hasPwsh : process.platform === 'win32') return;
+        process.env.verbose = verbose;
+        process.env.TRACE_TEST_OUTPUT = path.join(root, 'blackfire-config');
+        process.env.BLACKFIRE_SERVER_ID = 'example-blackfire-server-id';
+        process.env.BLACKFIRE_SERVER_TOKEN = 'example-blackfire-server-token';
+        process.env.BLACKFIRE_CLIENT_ID = 'example-blackfire-client-id';
+        process.env.BLACKFIRE_CLIENT_TOKEN = 'example-blackfire-client-token';
+        fs.writeFileSync(
+          helper,
+          fs.readFileSync(
+            path.join(
+              scripts,
+              'tools',
+              'blackfire' + (windows ? '.ps1' : '.sh')
+            ),
+            'utf8'
+          ) +
+            (windows
+              ? `
+function Invoke-RestMethod { @{cli='1.2.3'} }
+function Get-File {}
+function Expand-Archive {}
+function Add-ToProfile {}
+function Add-Log {}
+function blackfire { Add-Content $env:TRACE_TEST_OUTPUT ($args -join ' ') }
+$version = '8.4'
+$bin_dir = 'unused'
+Add-Blackfire
+Write-Output after-blackfire
+`
+              : `
+blackfire() { printf '%s\\n' "$@" >> "$TRACE_TEST_OUTPUT"; }
+os=Test
+blackfire_config
+echo after-blackfire
+`)
+        );
+        const prepared = await utils.addVerbose(run, platform);
+        const result = spawnSync(
+          windows ? 'pwsh' : 'bash',
+          windows ? ['-NoProfile', '-File', prepared] : [prepared],
+          {encoding: 'utf8', env: process.env}
+        );
+        expect(result.status).toBe(0);
+        expect(result.stdout + result.stderr).not.toContain(
+          'example-blackfire-'
+        );
+        expect(result.stdout).toContain('after-blackfire');
+        expect(
+          windows
+            ? /DEBUG:.*Write-Output after-blackfire/.test(result.stdout)
+            : result.stderr.includes('+ echo after-blackfire')
+        ).toBe(verbose !== 'true');
+        const config = fs.readFileSync(process.env.TRACE_TEST_OUTPUT!, 'utf8');
+        for (const value of [
+          'server-id',
+          'server-token',
+          'client-id',
+          'client-token'
+        ]) {
+          expect(config).toContain('example-blackfire-' + value);
+        }
+      }
+    );
+
+    it('keeps Composer credentials out of traces and resumes tracing', async () => {
+      if (platform === 'win32' ? !hasPwsh : process.platform === 'win32')
+        return;
+      process.env.verbose = 'vvv';
+      process.env.GITHUB_TOKEN = 'example-github-token';
+      process.env.COMPOSER_TOKEN = 'example-composer-token';
+      process.env.PACKAGIST_TOKEN = 'example-packagist-token';
+      process.env.COMPOSER_AUTH_JSON =
+        '{"bearer":{"example.org":"example-json-token"}}';
+      process.env.GITHUB_SERVER_URL = 'https://github.com';
+      const windows = platform === 'win32';
+      const source = fs.readFileSync(
+        path.join(scripts, 'tools', 'add_tools' + (windows ? '.ps1' : '.sh')),
+        'utf8'
+      );
+      fs.writeFileSync(
+        helper,
+        source +
+          (windows
+            ? `\n$composer_home='${root}'\nSet-ComposerAuth\nWrite-Output after-auth\n`
+            : `\ncomposer_home='${root}'\nset_composer_auth\necho after-auth\n`)
+      );
+      const prepared = await utils.addVerbose(run, platform);
+      const result = spawnSync(
+        windows ? 'pwsh' : 'bash',
+        windows ? ['-NoProfile', '-File', prepared] : [prepared],
+        {encoding: 'utf8', env: process.env}
+      );
+      expect(result.status).toBe(0);
+      expect(result.stdout + result.stderr).not.toMatch(
+        /example-(github|composer|packagist|json)-token/
+      );
+      expect(windows ? result.stdout : result.stderr).toMatch(
+        windows ? /DEBUG:.*Write-Output after-auth/ : /\+ echo after-auth/
+      );
+      const auth = JSON.parse(
+        fs.readFileSync(path.join(root, 'auth.json'), 'utf8')
+      );
+      expect(auth['github-oauth']['github.com']).toBe('example-composer-token');
+      expect(auth['http-basic']['repo.packagist.com'].password).toBe(
+        'example-packagist-token'
+      );
+      expect(auth.bearer['example.org']).toBe('example-json-token');
+    });
+
+    if (platform !== 'win32') {
+      (process.platform === 'win32' ? it.skip : it).each([
+        ['exit 37', 37],
+        ['set -e\nfalse', 1]
+      ])('preserves shell termination for %s', async (failure, status) => {
+        process.env.verbose = 'vvv';
+        process.env.GITHUB_TOKEN = 'example-github-token';
+        fs.writeFileSync(
+          helper,
+          `
+sensitive_failure() {
+  token="$GITHUB_TOKEN"
+  ${failure}
+  echo should-not-run
+}
+trap 'echo cleanup' EXIT
+without_trace sensitive_failure
+echo should-not-run
+`
+        );
+        const prepared = await utils.addVerbose(run, platform);
+        const result = spawnSync('bash', [prepared], {
+          encoding: 'utf8',
+          env: process.env
+        });
+        expect(result.status).toBe(status);
+        expect(result.stdout).toBe('cleanup\n');
+        expect(result.stdout + result.stderr).not.toContain(
+          'example-github-token'
+        );
+      });
+
+      (process.platform === 'win32' ? it.skip : it).each(['true', 'vv', 'vvv'])(
+        'protects Relay credentials and preserves tracing and status for verbose=%s',
+        async verbose => {
+          process.env.verbose = verbose;
+          const ini = path.join(root, 'relay.ini');
+          fs.writeFileSync(
+            helper,
+            fs.readFileSync(path.join(scripts, 'extensions/relay.sh'), 'utf8') +
+              '\nsudo() { if [ "$1" = rm ]; then return "$RELAY_TEST_STATUS"; fi; "$@"; }\n' +
+              `init_relay_ini '${ini}'\nrelay_status=$?\necho after-relay\nexit "$relay_status"\n`
+          );
+          const prepared = await utils.addVerbose(run, platform);
+          for (const status of [0, 37]) {
+            fs.writeFileSync(ini, '; relay.key =\n');
+            const result = spawnSync('bash', [prepared], {
+              encoding: 'utf8',
+              env: {
+                ...process.env,
+                RELAY_KEY: 'example-relay-key',
+                RELAY_TEST_STATUS: String(status)
+              }
+            });
+            expect(result.status).toBe(status);
+            expect(result.stdout + result.stderr).not.toContain(
+              'example-relay-key'
+            );
+            expect(result.stdout).toContain('after-relay');
+            expect(result.stderr.includes('+ echo after-relay')).toBe(
+              verbose !== 'true'
+            );
+            expect(fs.readFileSync(ini, 'utf8')).toBe(
+              'relay.key = example-relay-key\n'
+            );
+          }
+        }
+      );
+    }
+
+    (process.platform === 'win32' ? it.skip : it)(
+      'uses fresh copies without writing through source symlinks',
+      async () => {
+        const outside = path.join(root, path.basename(helper));
+        const original = 'echo original >/dev/null 2>&1\n';
+        fs.writeFileSync(outside, original);
+        fs.unlinkSync(helper);
+        fs.symlinkSync(outside, helper);
+        process.env.verbose = 'true';
+        const first = await utils.addVerbose(run, platform);
+        const second = await utils.addVerbose(run, platform);
+        expect(first).not.toBe(second);
+        expect(fs.readFileSync(outside, 'utf8')).toBe(original);
+        expect(fs.readFileSync(helper, 'utf8')).toBe(original);
+        expect(
+          fs.readFileSync(
+            path.join(path.dirname(first), 'tools', path.basename(helper)),
+            'utf8'
+          )
+        ).toBe('echo original \n');
+      }
+    );
+  }
+);