ci(docs-infra): improve preview-server logging

aio/aio-builds-setup/dockerbuild/scripts-js/lib/clean-up/build-cleaner.ts

@@ -5,11 +5,13 @@ import * as shell from 'shelljs';
 import {HIDDEN_DIR_PREFIX} from '../common/constants';
 import {GithubApi} from '../common/github-api';
 import {GithubPullRequests} from '../common/github-pull-requests';
-import {assertNotMissingOrEmpty, getPrInfoFromDownloadPath} from '../common/utils';
+import {assertNotMissingOrEmpty, createLogger, getPrInfoFromDownloadPath} from '../common/utils';
 
 // Classes
 export class BuildCleaner {
 
+  private logger = createLogger('BuildCleaner');
+
   // Constructor
   constructor(protected buildsDir: string, protected githubOrg: string, protected githubRepo: string,
               protected githubToken: string, protected downloadsDir: string, protected artifactPath: string) {
@@ -77,15 +79,15 @@ export class BuildCleaner {
         shell.rm('-rf', dir);
       }
     } catch (err) {
-      console.error(`ERROR: Unable to remove '${dir}' due to:`, err);
+      this.logger.error(`ERROR: Unable to remove '${dir}' due to:`, err);
     }
   }
 
   public removeUnnecessaryBuilds(existingBuildNumbers: number[], openPrNumbers: number[]) {
     const toRemove = existingBuildNumbers.filter(num => !openPrNumbers.includes(num));
 
-    console.log(`Existing builds: ${existingBuildNumbers.length}`);
+    this.logger.log(`Existing builds: ${existingBuildNumbers.length}`);
-    console.log(`Removing ${toRemove.length} build(s): ${toRemove.join(', ')}`);
+    this.logger.log(`Removing ${toRemove.length} build(s): ${toRemove.join(', ')}`);
 
     // Try removing public dirs.
     toRemove.
@@ -117,8 +119,8 @@ export class BuildCleaner {
       return !openPrNumbers.includes(pr);
     });
 
-    console.log(`Existing downloads: ${existingDownloads.length}`);
+    this.logger.log(`Existing downloads: ${existingDownloads.length}`);
-    console.log(`Removing ${toRemove.length} download(s): ${toRemove.join(', ')}`);
+    this.logger.log(`Removing ${toRemove.length} download(s): ${toRemove.join(', ')}`);
 
     toRemove.forEach(filePath => shell.rm(filePath));
   }

aio/aio-builds-setup/dockerbuild/scripts-js/lib/clean-up/index.ts

@@ -14,8 +14,6 @@ _main();
 
 // Functions
 function _main() {
-  console.log(`[${new Date()}] - Cleaning up builds...`);
-
   const buildCleaner = new BuildCleaner(
     AIO_BUILDS_DIR,
     AIO_GITHUB_ORGANIZATION,
@@ -24,8 +22,5 @@ function _main() {
     AIO_DOWNLOADS_DIR,
     AIO_ARTIFACT_PATH);
 
-  buildCleaner.cleanUp().catch(err => {
+  buildCleaner.cleanUp().catch(() => process.exit(1));
-    console.error('ERROR:', err);
-    process.exit(1);
-  });
 }

aio/aio-builds-setup/dockerbuild/scripts-js/lib/common/utils.ts

@@ -73,3 +73,13 @@ export const getEnvVar = (name: string, isOptional = false): string => {
 
   return value || '';
 };
+
+export function createLogger(scope: string) {
+  const padding = ' '.repeat(20 - scope.length);
+  return {
+    error: (...args: any[]) => console.error(`[${new Date()}]`, `${scope}:${padding}`, ...args),
+    info: (...args: any[]) => console.info(`[${new Date()}]`, `${scope}:${padding}`, ...args),
+    log: (...args: any[]) => console.log(`[${new Date()}]`, `${scope}:${padding}`, ...args),
+    warn: (...args: any[]) => console.warn(`[${new Date()}]`, `${scope}:${padding}`, ...args),
+  };
+}

aio/aio-builds-setup/dockerbuild/scripts-js/lib/upload-server/build-creator.ts

@@ -5,12 +5,15 @@ import * as fs from 'fs';
 import * as path from 'path';
 import * as shell from 'shelljs';
 import {HIDDEN_DIR_PREFIX} from '../common/constants';
-import {assertNotMissingOrEmpty, computeShortSha} from '../common/utils';
+import {assertNotMissingOrEmpty, computeShortSha, createLogger} from '../common/utils';
 import {ChangedPrVisibilityEvent, CreatedBuildEvent} from './build-events';
 import {UploadError} from './upload-error';
 
 // Classes
 export class BuildCreator extends EventEmitter {
+
+  private logger = createLogger('BuildCreator');
+
   // Constructor
   constructor(protected buildsDir: string) {
     super();
@@ -102,7 +105,7 @@ export class BuildCreator extends EventEmitter {
         }
 
         if (stderr) {
-          console.warn(stderr);
+          this.logger.warn(stderr);
         }
 
         try {

aio/aio-builds-setup/dockerbuild/scripts-js/lib/upload-server/index-preverify-pr.ts

@@ -1,43 +0,0 @@
-// Imports
-import {GithubApi} from '../common/github-api';
-import {GithubPullRequests} from '../common/github-pull-requests';
-import {GithubTeams} from '../common/github-teams';
-import {getEnvVar} from '../common/utils';
-import {BuildVerifier} from './build-verifier';
-
-// Run
-_main();
-
-// Functions
-function _main() {
-  const githubToken = getEnvVar('AIO_GITHUB_TOKEN');
-  const githubOrg = getEnvVar('AIO_GITHUB_ORGANIZATION');
-  const githubRepo = getEnvVar('AIO_GITHUB_REPO');
-  const allowedTeamSlugs = getEnvVar('AIO_GITHUB_TEAM_SLUGS').split(',');
-  const trustedPrLabel = getEnvVar('AIO_TRUSTED_PR_LABEL');
-  const pr = +getEnvVar('AIO_PREVERIFY_PR');
-
-  const githubApi = new GithubApi(githubToken);
-  const prs = new GithubPullRequests(githubApi, githubOrg, githubRepo);
-  const teams = new GithubTeams(githubApi, githubOrg);
-  const buildVerifier = new BuildVerifier(prs, teams, allowedTeamSlugs, trustedPrLabel);
-
-  // Exit codes:
-  // - 0: The PR can be automatically trusted (i.e. author belongs to trusted team or PR has the "trusted PR" label).
-  // - 1: An error occurred.
-  // - 2: The PR cannot be automatically trusted.
-  buildVerifier.getPrIsTrusted(pr).
-    then(isTrusted => {
-      if (!isTrusted) {
-        console.warn(
-            `The PR cannot be automatically verified, because it doesn't have the "${trustedPrLabel}" label and the ` +
-            `the author is not an active member of any of the following teams: ${allowedTeamSlugs.join(', ')}`);
-      }
-
-      process.exit(isTrusted ? 0 : 2);
-    }).
-    catch(err => {
-      console.error(err);
-      process.exit(1);
-    });
-}

aio/aio-builds-setup/dockerbuild/scripts-js/lib/upload-server/utils.ts

@@ -1,5 +1,4 @@
 import * as express from 'express';
-import * as http from 'http';
 import {promisify} from 'util';
 import {UploadError} from './upload-error';
 
@@ -13,10 +12,6 @@ export async function respondWithError(res: express.Response, err: any) {
     err = new UploadError(500, String((err && err.message) || err));
   }
 
-  const statusText = http.STATUS_CODES[err.status] || '???';
-  console.error(`Upload error: ${err.status} - ${statusText}`);
-  console.error(err.message);
-
   res.status(err.status);
   await promisify(res.end.bind(res))(err.message);
 }

aio/aio-builds-setup/dockerbuild/scripts-js/lib/verify-setup/helper.ts

@@ -11,7 +11,7 @@ import {
   AIO_NGINX_PORT_HTTPS,
   AIO_WWW_USER,
 } from '../common/env-variables';
-import {computeShortSha} from '../common/utils';
+import {computeShortSha, createLogger} from '../common/utils';
 
 // Interfaces - Types
 export interface CmdResult { success: boolean; err: Error | null; stdout: string; stderr: string; }
@@ -23,6 +23,7 @@ export type VerifyCmdResultFn = (result: CmdResult) => void;
 
 // Classes
 class Helper {
+
   // Properties - Protected
   protected cleanUpFns: CleanUpFn[] = [];
   protected portPerScheme: {[scheme: string]: number} = {
@@ -30,6 +31,8 @@ class Helper {
     https: AIO_NGINX_PORT_HTTPS,
   };
 
+  private logger = createLogger('TestHelper');
+
   // Constructor
   constructor() {
     shell.mkdir('-p', AIO_BUILDS_DIR);
@@ -49,12 +52,12 @@ class Helper {
     const leftoverBuilds = fs.readdirSync(AIO_BUILDS_DIR);
 
     if (leftoverDownloads.length) {
-      console.log(`Downloads directory '${AIO_DOWNLOADS_DIR}' is not empty after clean-up.`, leftoverDownloads);
+      this.logger.log(`Downloads directory '${AIO_DOWNLOADS_DIR}' is not empty after clean-up.`, leftoverDownloads);
       shell.rm('-rf', `${AIO_DOWNLOADS_DIR}/*`);
     }
 
     if (leftoverBuilds.length) {
-      console.log(`Builds directory '${AIO_BUILDS_DIR}' is not empty after clean-up.`, leftoverBuilds);
+      this.logger.log(`Builds directory '${AIO_BUILDS_DIR}' is not empty after clean-up.`, leftoverBuilds);
       shell.rm('-rf', `${AIO_BUILDS_DIR}/*`);
     }
 
@@ -122,9 +125,9 @@ class Helper {
                      // Only keep the last to sections (final headers and body).
 
       if (!result.success) {
-        console.log('Stdout:', result.stdout);
+        this.logger.log('Stdout:', result.stdout);
-        console.log('Stderr:', result.stderr);
+        this.logger.error('Stderr:', result.stderr);
-        console.log('Error:', result.err);
+        this.logger.error('Error:', result.err);
       }
 
       expect(result.success).toBe(true);

aio/aio-builds-setup/dockerbuild/scripts-js/lib/verify-setup/mock-external-apis.ts

@@ -2,7 +2,7 @@
 import * as nock from 'nock';
 import * as tar from 'tar-stream';
 import {gzipSync} from 'zlib';
-import {getEnvVar} from '../common/utils';
+import {createLogger, getEnvVar} from '../common/utils';
 import {BuildNums, PrNums, SHA} from './constants';
 
 // We are using the `nock` library to fake responses from REST requests, when testing.
@@ -14,11 +14,12 @@ import {BuildNums, PrNums, SHA} from './constants';
 // below and return a suitable response. This is quite complicated to setup since the
 // response from, say, CircleCI will affect what request is made to, say, Github.
 
+const logger = createLogger('NOCK');
+
 const log = (...args: any[]) => {
   // Filter out non-matching URL checks
   if (!/^matching.+: false$/.test(args[0])) {
-    args.unshift('>> NOCK:');
+    logger.log(...args);
-    console.log.apply(console, args);
   }
 };
 
@@ -80,7 +81,7 @@ const getCommentUrl = (prNum: number) => `${getIssueUrl(prNum)}/comments`;
 const getTeamMembershipUrl = (teamId: number, username: string) => `/teams/${teamId}/memberships/${username}`;
 
 const createArchive = (buildNum: number, prNum: number, sha: string) => {
-  console.log('createArchive', buildNum, prNum, sha);
+  logger.log('createArchive', buildNum, prNum, sha);
   const pack = tar.pack();
   pack.entry({name: 'index.html'}, `BUILD: ${buildNum} | PR: ${prNum} | SHA: ${sha} | File: /index.html`);
   pack.entry({name: 'foo/bar.js'}, `BUILD: ${buildNum} | PR: ${prNum} | SHA: ${sha} | File: /foo/bar.js`);

aio/aio-builds-setup/dockerbuild/scripts-js/test/clean-up/build-cleaner.spec.ts

@@ -14,13 +14,17 @@ const EXISTING_DOWNLOADS = [
   'downloads/20-1234567-build.zip',
 ];
 const OPEN_PRS = [10, 40];
+const ANY_DATE = jasmine.any(String);
 
 // Tests
 describe('BuildCleaner', () => {
   let cleaner: BuildCleaner;
 
-  beforeEach(() => cleaner = new BuildCleaner('/foo/bar', 'baz', 'qux', '12345', 'downloads', 'build.zip'));
+  beforeEach(() => {
-
+    spyOn(console, 'error');
+    spyOn(console, 'log');
+    cleaner = new BuildCleaner('/foo/bar', 'baz', 'qux', '12345', 'downloads', 'build.zip');
+  });
 
   describe('constructor()', () => {
 
@@ -78,7 +82,6 @@ describe('BuildCleaner', () => {
       cleanerRemoveUnnecessaryBuildsSpy = spyOn(cleaner, 'removeUnnecessaryBuilds');
       cleanerRemoveUnnecessaryDownloadsSpy = spyOn(cleaner, 'removeUnnecessaryDownloads');
 
-      spyOn(console, 'log');
     });
 
 
@@ -276,7 +279,7 @@ describe('BuildCleaner', () => {
 
     it('should log the number of open PRs', () => {
       promise.then(prNumbers => {
-        expect(console.log).toHaveBeenCalledWith(`Open pull requests: ${prNumbers}`);
+        expect(console.log).toHaveBeenCalledWith(ANY_DATE, 'BuildCleaner:        ', `Open pull requests: ${prNumbers}`);
       });
     });
   });
@@ -373,7 +376,6 @@ describe('BuildCleaner', () => {
 
 
     it('should catch errors and log them', () => {
-      const consoleErrorSpy = spyOn(console, 'error');
       shellRmSpy.and.callFake(() => {
         // tslint:disable-next-line: no-string-throw
         throw 'Test';
@@ -381,9 +383,8 @@ describe('BuildCleaner', () => {
 
       cleaner.removeDir('/foo/bar');
 
-      expect(consoleErrorSpy).toHaveBeenCalled();
+      expect(console.error).toHaveBeenCalledWith(
-      expect(consoleErrorSpy.calls.argsFor(0)[0]).toContain('Unable to remove \'/foo/bar\'');
+        jasmine.any(String), 'BuildCleaner:        ', 'ERROR: Unable to remove \'/foo/bar\' due to:', 'Test');
-      expect(consoleErrorSpy.calls.argsFor(0)[1]).toBe('Test');
     });
 
   });
@@ -393,7 +394,6 @@ describe('BuildCleaner', () => {
     let cleanerRemoveDirSpy: jasmine.Spy;
 
     beforeEach(() => {
-      spyOn(console, 'log');
       cleanerRemoveDirSpy = spyOn(cleaner, 'removeDir');
     });
 
@@ -401,8 +401,8 @@ describe('BuildCleaner', () => {
     it('should log the number of existing builds and builds to be removed', () => {
       cleaner.removeUnnecessaryBuilds([1, 2, 3], [3, 4, 5, 6]);
 
-      expect(console.log).toHaveBeenCalledWith('Existing builds: 3');
+      expect(console.log).toHaveBeenCalledWith(ANY_DATE, 'BuildCleaner:        ', 'Existing builds: 3');
-      expect(console.log).toHaveBeenCalledWith('Removing 2 build(s): 1, 2');
+      expect(console.log).toHaveBeenCalledWith(ANY_DATE, 'BuildCleaner:        ', 'Removing 2 build(s): 1, 2');
     });
 
 
@@ -455,7 +455,6 @@ describe('BuildCleaner', () => {
 
   describe('removeUnnecessaryDownloads()', () => {
     beforeEach(() => {
-      spyOn(console, 'log');
       spyOn(shell, 'rm');
     });
 
@@ -471,8 +470,8 @@ describe('BuildCleaner', () => {
     it('should log the number of existing builds and builds to be removed', () => {
       cleaner.removeUnnecessaryDownloads(EXISTING_DOWNLOADS, OPEN_PRS);
 
-      expect(console.log).toHaveBeenCalledWith('Existing downloads: 4');
+      expect(console.log).toHaveBeenCalledWith(ANY_DATE, 'BuildCleaner:        ', 'Existing downloads: 4');
-      expect(console.log).toHaveBeenCalledWith(
+      expect(console.log).toHaveBeenCalledWith(ANY_DATE, 'BuildCleaner:        ',
         'Removing 2 download(s): downloads/20-ABCDEF0-build.zip, downloads/20-1234567-build.zip');
     });
   });

aio/aio-builds-setup/dockerbuild/scripts-js/test/upload-server/build-creator.spec.ts

@@ -511,7 +511,8 @@ describe('BuildCreator', () => {
 
     it('should log (as a warning) any stderr output if extracting succeeded', done => {
       (bc as any).extractArchive('foo', 'bar').
-        then(() => expect(consoleWarnSpy).toHaveBeenCalledWith('This is stderr')).
+        then(() => expect(consoleWarnSpy)
+          .toHaveBeenCalledWith(jasmine.any(String), 'BuildCreator:        ', 'This is stderr')).
         then(done);
 
       cpExecCbs[0](null, 'This is stdout', 'This is stderr');

aio/aio-builds-setup/dockerbuild/scripts-js/test/upload-server/upload-server-factory.spec.ts

@@ -43,6 +43,11 @@ describe('uploadServerFactory', () => {
   const createUploadServer = (partialConfig: Partial<UploadServerConfig> = {}) =>
     UploadServerFactory.create({...defaultConfig, ...partialConfig});
 
+  beforeEach(() => {
+    spyOn(console, 'error');
+    spyOn(console, 'info');
+    spyOn(console, 'log');
+  });
 
   describe('create()', () => {
     let usfCreateMiddlewareSpy: jasmine.Spy;
@@ -132,14 +137,14 @@ describe('uploadServerFactory', () => {
 
 
     it('should log the server address info on \'listening\'', () => {
-      const consoleInfoSpy = spyOn(console, 'info');
       const server = createUploadServer();
       server.address = () => ({address: 'foo', family: '', port: 1337});
 
-      expect(consoleInfoSpy).not.toHaveBeenCalled();
+      expect(console.info).not.toHaveBeenCalled();
 
       server.emit('listening');
-      expect(consoleInfoSpy).toHaveBeenCalledWith('Up and running (and listening on foo:1337)...');
+      expect(console.info).toHaveBeenCalledWith(
+        jasmine.any(String), 'UploadServer:        ', 'Up and running (and listening on foo:1337)...');
     });
 
   });
@@ -254,8 +259,6 @@ describe('uploadServerFactory', () => {
       const middleware = UploadServerFactory.createMiddleware(buildRetriever, buildVerifier, buildCreator,
                                                               defaultConfig);
       agent = supertest.agent(middleware);
-
-      spyOn(console, 'error');
     });
 
     describe('GET /health-check', () => {
@@ -364,12 +367,11 @@ describe('uploadServerFactory', () => {
       });
 
       it('should respond with 204 if the build did not affect any significant files', async () => {
-        spyOn(console, 'log');
         AFFECTS_SIGNIFICANT_FILES = false;
         await agent.post(URL).send(BASIC_PAYLOAD).expect(204);
         expect(getGithubInfoSpy).toHaveBeenCalledWith(BUILD_NUM);
         expect(getSignificantFilesChangedSpy).toHaveBeenCalledWith(PR, jasmine.any(RegExp));
-        expect(console.log).toHaveBeenCalledWith(
+        expect(console.log).toHaveBeenCalledWith(jasmine.any(String), 'UploadServer:        ',
           'PR:777, Build:12345 - Skipping preview processing because this PR did not touch any significant files.');
         expect(downloadBuildArtifactSpy).not.toHaveBeenCalled();
         expect(getPrIsTrustedSpy).not.toHaveBeenCalled();

aio/aio-builds-setup/dockerbuild/scripts-js/test/upload-server/utils.spec.ts

@@ -16,20 +16,14 @@ describe('upload-server/utils', () => {
 
     it('should set the status on the response', () => {
       respondWithError(response, new UploadError(505, 'TEST MESSAGE'));
-
       expect(statusSpy).toHaveBeenCalledWith(505);
       expect(endSpy).toHaveBeenCalledWith('TEST MESSAGE', jasmine.any(Function));
-      expect(console.error).toHaveBeenCalledWith('Upload error: 505 - HTTP Version Not Supported');
-      expect(console.error).toHaveBeenCalledWith('TEST MESSAGE');
     });
 
     it('should convert non-UploadError errors to 500 UploadErrors', () => {
       respondWithError(response, new Error('OTHER MESSAGE'));
-
       expect(statusSpy).toHaveBeenCalledWith(500);
       expect(endSpy).toHaveBeenCalledWith('OTHER MESSAGE', jasmine.any(Function));
-      expect(console.error).toHaveBeenCalledWith('Upload error: 500 - Internal Server Error');
-      expect(console.error).toHaveBeenCalledWith('OTHER MESSAGE');
     });
   });