Add logging to node download (microsoft#184070)

Add logging to node download. For microsoft#182951

Author: aeschli

build/gulpfile.reh.js

@@ -29,6 +29,7 @@ const { compileBuildTask } = require('./gulpfile.compile');
 const { compileExtensionsBuildTask, compileExtensionMediaBuildTask } = require('./gulpfile.extensions');
 const { vscodeWebEntryPoints, vscodeWebResourceIncludes, createVSCodeWebFileContentMapper } = require('./gulpfile.vscode.web');
 const cp = require('child_process');
+const log = require('fancy-log');
 
 const REPO_ROOT = path.dirname(__dirname);
 const commit = getVersion(REPO_ROOT);
@@ -163,25 +164,27 @@ function nodejs(platform, arch) {
 
 	if (platform === 'win32') {
 		if (product.nodejsRepository) {
+			log(`Downloading node.js ${nodeVersion} ${platform} ${arch} from ${product.nodejsRepository}...`);
 			return assetFromGithub(product.nodejsRepository, nodeVersion, name => name === `win-${arch}-node.exe`)
 				.pipe(rename('node.exe'));
 		}
-
-		return remote(`/dist/v${nodeVersion}/win-${arch}/node.exe`, { base: 'https://nodejs.org' })
+		log(`Downloading node.js ${nodeVersion} ${platform} ${arch} from https://nodejs.org`);
+		return remote(`/dist/v${nodeVersion}/win-${arch}/node.exe`, { base: 'https://nodejs.org', verbose: true })
 			.pipe(rename('node.exe'));
 	}
 
 	if (arch === 'alpine' || platform === 'alpine') {
 		const imageName = arch === 'arm64' ? 'arm64v8/node' : 'node';
+		log(`Downloading node.js ${nodeVersion} ${platform} ${arch} from docker image ${imageName}`);
 		const contents = cp.execSync(`docker run --rm ${imageName}:${nodeVersion}-alpine /bin/sh -c 'cat \`which node\`'`, { maxBuffer: 100 * 1024 * 1024, encoding: 'buffer' });
 		return es.readArray([new File({ path: 'node', contents, stat: { mode: parseInt('755', 8) } })]);
 	}
 
 	if (arch === 'armhf') {
 		arch = 'armv7l';
 	}
-
-	return remote(`/dist/v${nodeVersion}/node-v${nodeVersion}-${platform}-${arch}.tar.gz`, { base: 'https://nodejs.org' })
+	log(`Downloading node.js ${nodeVersion} ${platform} ${arch} from https://nodejs.org`);
+	return remote(`/dist/v${nodeVersion}/node-v${nodeVersion}-${platform}-${arch}.tar.gz`, { base: 'https://nodejs.org', verbose: true })
 		.pipe(flatmap(stream => stream.pipe(gunzip()).pipe(untar())))
 		.pipe(filter('**/node'))
 		.pipe(util.setExecutableBit('**'))

build/lib/gulpRemoteSource.js

@@ -7,11 +7,14 @@ import * as es from 'event-stream';
 import fetch, { RequestInit } from 'node-fetch';
 import * as VinylFile from 'vinyl';
 import * as through2 from 'through2';
+import * as log from 'fancy-log';
+import * as ansiColors from 'ansi-colors';
 
 export interface IOptions {
 	base?: string;
 	buffer?: boolean;
 	fetchOptions?: RequestInit;
+	verbose?: boolean;
 }
 
 export function remote(urls: string[] | string, options: IOptions): es.ThroughStream {
@@ -41,9 +44,17 @@ export function remote(urls: string[] | string, options: IOptions): es.ThroughSt
 	}));
 }
 
-async function fetchWithRetry(url: string, options: IOptions, retries = 3, retryDelay = 1000): Promise<VinylFile> {
+async function fetchWithRetry(url: string, options: IOptions, retries = 3, retryDelay = 250): Promise<VinylFile> {
 	try {
+		let startTime = 0;
+		if (options.verbose) {
+			log(`Start fetching ${ansiColors.magenta(url)}${retries !== 3 ? `(${3 - retries} retry}` : ''}`);
+			startTime = new Date().getTime();
+		}
 		const response = await fetch(url, options.fetchOptions);
+		if (options.verbose) {
+			log(`Fetch completed: Status ${response.status}. Took ${ansiColors.magenta(`${new Date().getTime() - startTime} ms`)}`);
+		}
 		if (response.ok && (response.status >= 200 && response.status < 300)) {
 			// request must be piped out once created, or we'll get this error: "You cannot pipe after data has been emitted from the response."
 			const contents = options.buffer ? await response.buffer() : response.body.pipe(through2());
@@ -54,12 +65,15 @@ async function fetchWithRetry(url: string, options: IOptions, retries = 3, retry
 				contents
 			});
 		}
-		throw new Error(`Request ${url} failed with status code: ${response.status}`);
+		throw new Error(`Request ${ansiColors.magenta(url)} failed with status code: ${response.status}`);
 	} catch (e) {
 		if (retries > 0) {
 			await new Promise(c => setTimeout(c, retryDelay));
 			return fetchWithRetry(url, options, retries - 1, retryDelay * 3);
 		}
+		if (options.verbose) {
+			log(`Fetching ${ansiColors.cyan(url)} failed: ${e}`);
+		}
 		throw e;
 	}
 }