From 5a41ef502c95ad52d43cd0827aeb7b241d554673 Mon Sep 17 00:00:00 2001 From: Jasper De Moor Date: Thu, 17 May 2018 17:08:10 +0200 Subject: [PATCH 1/4] add debug mode --- src/Asset.js | 5 +++++ src/Bundle.js | 5 +++++ src/Bundler.js | 25 +++++++++++++++++++++++++ src/Logger.js | 41 ++++++++++++++++++++++++++++++++++++----- src/cli.js | 6 +++--- 5 files changed, 74 insertions(+), 8 deletions(-) diff --git a/src/Asset.js b/src/Asset.js index c3fc95d6aa2..3319430487b 100644 --- a/src/Asset.js +++ b/src/Asset.js @@ -149,6 +149,7 @@ class Asset { } async load() { + logger.verbose(`Loading ${this.basename} from the filesystem...`); return await fs.readFile(this.name, this.encoding); } @@ -177,9 +178,13 @@ class Asset { async process() { if (!this.generated) { await this.loadIfNeeded(); + logger.verbose(`PreTransforming ${this.basename}...`); await this.pretransform(); + logger.verbose(`Getting dependencies of ${this.basename}...`); await this.getDependencies(); + logger.verbose(`Transforming ${this.basename}...`); await this.transform(); + logger.verbose(`Generating ${this.basename}...`); this.generated = await this.generate(); this.hash = await this.generateHash(); } diff --git a/src/Bundle.js b/src/Bundle.js index dc7d277c395..7d5d5b81b9c 100644 --- a/src/Bundle.js +++ b/src/Bundle.js @@ -1,5 +1,6 @@ const Path = require('path'); const crypto = require('crypto'); +const logger = require('./Logger'); /** * A Bundle represents an output file, containing multiple assets. Bundles can have @@ -184,17 +185,21 @@ class Bundle { async _package(bundler) { let Packager = bundler.packagers.get(this.type); let packager = new Packager(this, bundler); + let basename = Path.basename(this.name); let startTime = Date.now(); await packager.setup(); await packager.start(); + logger.verbose(`Started packaging ${basename}...`); let included = new Set(); for (let asset of this.assets) { + logger.verbose(`Adding ${asset.basename} to ${basename}...`); await this._addDeps(asset, packager, included); } await packager.end(); + logger.verbose(`Finished packaging ${basename}...`); this.bundleTime = Date.now() - startTime; for (let asset of this.assets) { diff --git a/src/Bundler.js b/src/Bundler.js index 163cd6a1d48..0d877176626 100644 --- a/src/Bundler.js +++ b/src/Bundler.js @@ -65,6 +65,14 @@ class Bundler extends EventEmitter { this.rebuildTimeout = null; logger.setOptions(this.options); + + // Print all bundler options if parcel is in debug mode + if (this.options.logLevel > 4) { + logger.verbose(`Bundler options:`); + Object.keys(this.options).forEach(key => { + logger.verbose(` ${key}: ${this.options[key]}`); + }); + } } normalizeEntries(entryFiles) { @@ -190,6 +198,7 @@ class Bundler extends EventEmitter { const pattern = /^(@.*\/)?parcel-plugin-.+/; if (pattern.test(dep)) { let plugin = await localRequire(dep, relative); + logger.verbose(`Load plugin: ${dep}...`); await plugin(this); } } @@ -315,6 +324,8 @@ class Bundler extends EventEmitter { return; } + logger.verbose(`Start bundler...`); + await this.loadPlugins(); await loadEnv(Path.join(this.options.rootDir, 'index')); @@ -379,6 +390,7 @@ class Bundler extends EventEmitter { } if (!this.watchedAssets.has(path)) { + logger.verbose(`Add ${path} to filewatcher...`); this.watcher.watch(path); this.watchedAssets.set(path, new Set()); } @@ -395,6 +407,7 @@ class Bundler extends EventEmitter { watched.delete(asset); if (watched.size === 0) { + logger.verbose(`Remove ${path} from filewatcher...`); this.watchedAssets.delete(path); this.watcher.unwatch(path); } @@ -489,6 +502,7 @@ class Bundler extends EventEmitter { if (!this.errored) { logger.status(emoji.progress, `Building ${asset.basename}...`); + logger.verbose(`Queuing ${asset.basename}...`); } // Mark the asset processed so we don't load it twice @@ -499,14 +513,21 @@ class Bundler extends EventEmitter { let processed = this.cache && (await this.cache.read(asset.name)); let cacheMiss = false; if (!processed || asset.shouldInvalidate(processed.cacheData)) { + logger.verbose( + `${!processed ? 'Cache miss,' : 'Invalidated,'} ${asset.basename}...` + ); processed = await this.farm.run(asset.name); cacheMiss = true; + } else { + logger.verbose(`Copied ${asset.basename} from cache...`); } asset.buildTime = Date.now() - startTime; asset.generated = processed.generated; asset.hash = processed.hash; + logger.verbose(`Finished building ${asset.basename}...`); + // Call the delegate to get implicit dependencies let dependencies = processed.dependencies; if (this.delegate.getImplicitDependencies) { @@ -527,6 +548,9 @@ class Bundler extends EventEmitter { } else { let assetDep = await this.resolveDep(asset, dep); if (assetDep) { + logger.verbose( + `Load dependency ${assetDep.basename} of ${asset.basename}...` + ); await this.loadAsset(assetDep); } @@ -685,6 +709,7 @@ class Bundler extends EventEmitter { } logger.clear(); + logger.verbose(`Detected a change in ${path}...`); logger.status(emoji.progress, `Building ${Path.basename(path)}...`); // Add the asset to the rebuild queue, and reset the timeout. diff --git a/src/Logger.js b/src/Logger.js index 4ea682a4ac2..2c045efca26 100644 --- a/src/Logger.js +++ b/src/Logger.js @@ -4,6 +4,9 @@ const prettyError = require('./utils/prettyError'); const emoji = require('./utils/emoji'); const {countBreaks} = require('grapheme-breaker'); const stripAnsi = require('strip-ansi'); +const promisify = require('./utils/promisify'); +const path = require('path'); +const fs = require('fs'); class Logger { constructor(options) { @@ -51,6 +54,31 @@ class Logger { this._log(message); } + verbose(message) { + if (this.logLevel < 4) { + return; + } + + let currDate = new Date(); + message = `[${currDate.toLocaleTimeString()}]: ${message}`; + + if (this.logLevel > 4) { + if (!this.logFile) { + this.logFile = fs.createWriteStream( + path.join( + process.cwd(), + `parcel-debug-${currDate.toLocaleDateString()}@${currDate.toLocaleTimeString()}.log` + ) + ); + this.logFile.write = promisify(this.logFile.write.bind(this.logFile)); + } + + this.logFile.write(message + '\n'); + } + + this.write(message); + } + log(message) { if (this.logLevel < 3) { return; @@ -93,7 +121,7 @@ class Logger { } clear() { - if (!this.color || this.isTest) { + if (!this.color || this.isTest || this.logLevel > 3) { return; } @@ -127,15 +155,18 @@ class Logger { return; } + let msgContent = this.chalk[color].bold(`${emoji} ${message}`); + + if (this.logLevel > 3) { + return this.verbose(msgContent); + } + let hasStatusLine = this.statusLine != null; if (!hasStatusLine) { this.statusLine = this.lines; } - this.writeLine( - this.statusLine, - this.chalk[color].bold(`${emoji} ${message}`) - ); + this.writeLine(this.statusLine, msgContent); if (!hasStatusLine) { process.stdout.write('\n'); diff --git a/src/cli.js b/src/cli.js index bfa36a1345b..c88db02f9bc 100755 --- a/src/cli.js +++ b/src/cli.js @@ -55,7 +55,7 @@ program .option( '--log-level ', 'set the log level, either "0" (no output), "1" (errors), "2" (warnings + errors) or "3" (all).', - /^([0-3])$/ + /^([0-5])$/ ) .action(bundle); @@ -99,7 +99,7 @@ program .option( '--log-level ', 'set the log level, either "0" (no output), "1" (errors), "2" (warnings + errors) or "3" (all).', - /^([0-3])$/ + /^([0-5])$/ ) .action(bundle); @@ -134,7 +134,7 @@ program .option( '--log-level ', 'set the log level, either "0" (no output), "1" (errors), "2" (warnings + errors) or "3" (all).', - /^([0-3])$/ + /^([0-5])$/ ) .action(bundle); From cca47e8bddd207b164b8e212db094b59d26f7dc0 Mon Sep 17 00:00:00 2001 From: Jasper De Moor Date: Fri, 18 May 2018 11:02:52 +0200 Subject: [PATCH 2/4] add warnings and persistent lines to debug log --- src/Logger.js | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/src/Logger.js b/src/Logger.js index 2c045efca26..11817d62c1c 100644 --- a/src/Logger.js +++ b/src/Logger.js @@ -47,6 +47,10 @@ class Logger { } write(message, persistent = false) { + if (this.logLevel > 3) { + return this.verbose(message); + } + if (!persistent) { this.lines += this.countLines(message); } @@ -76,7 +80,7 @@ class Logger { this.logFile.write(message + '\n'); } - this.write(message); + this._log(message); } log(message) { From 17de8b24c27f8f83b5e564fdabd5864befbf6f5e Mon Sep 17 00:00:00 2001 From: Jasper De Moor Date: Wed, 27 Jun 2018 14:44:51 +0200 Subject: [PATCH 3/4] strip ansi in logfile --- src/Logger.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Logger.js b/src/Logger.js index 11817d62c1c..afe9d598a24 100644 --- a/src/Logger.js +++ b/src/Logger.js @@ -77,7 +77,7 @@ class Logger { this.logFile.write = promisify(this.logFile.write.bind(this.logFile)); } - this.logFile.write(message + '\n'); + this.logFile.write(stripAnsi(message) + '\n'); } this._log(message); From 98e6313039597b4643e5ff5564772287d75d2ae9 Mon Sep 17 00:00:00 2001 From: Jasper De Moor Date: Wed, 27 Jun 2018 17:40:45 +0200 Subject: [PATCH 4/4] add some more verbose logging --- src/Asset.js | 2 ++ src/Bundler.js | 58 ++++++++++++++++++++++++++++++++++++++++++++------ 2 files changed, 54 insertions(+), 6 deletions(-) diff --git a/src/Asset.js b/src/Asset.js index 3319430487b..fd7539ec24e 100644 --- a/src/Asset.js +++ b/src/Asset.js @@ -189,6 +189,8 @@ class Asset { this.hash = await this.generateHash(); } + logger.verbose(`${this.basename} processed`); + return this.generated; } diff --git a/src/Bundler.js b/src/Bundler.js index 0d877176626..4057d328f4a 100644 --- a/src/Bundler.js +++ b/src/Bundler.js @@ -70,7 +70,7 @@ class Bundler extends EventEmitter { if (this.options.logLevel > 4) { logger.verbose(`Bundler options:`); Object.keys(this.options).forEach(key => { - logger.verbose(` ${key}: ${this.options[key]}`); + logger.verbose(` ${key}: ${JSON.stringify(this.options[key])}`); }); } } @@ -241,6 +241,8 @@ class Bundler extends EventEmitter { } } + logger.verbose('[Bundler] Build the queued assets...'); + // Build the queued assets. let loadedAssets = await this.buildQueue.run(); @@ -248,42 +250,60 @@ class Bundler extends EventEmitter { // plus the ones that were in the build queue. let changedAssets = [...this.findOrphanAssets(), ...loadedAssets]; + logger.verbose('[Bundler] Invalidating bundles...'); + // Invalidate bundles for (let asset of this.loadedAssets.values()) { asset.invalidateBundle(); } + logger.verbose('[Bundler] bundles invalidated...'); + + logger.verbose('[Bundler] Create root bundle...'); + // Create a root bundle to hold all of the entry assets, and add them to the tree. this.mainBundle = new Bundle(); for (let asset of this.entryAssets) { this.createBundleTree(asset, this.mainBundle); } + logger.verbose('[Bundler] Root bundle created.'); + // If there is only one child bundle, replace the root with that bundle. if (this.mainBundle.childBundles.size === 1) { this.mainBundle = Array.from(this.mainBundle.childBundles)[0]; } + logger.verbose('[Bundler] Generating bundle hash...'); + // Generate the final bundle names, and replace references in the built assets. this.bundleNameMap = this.mainBundle.getBundleNameMap( this.options.contentHash ); + logger.verbose('[Bundler] Updating bundle name references...'); + for (let asset of changedAssets) { asset.replaceBundleNames(this.bundleNameMap); } + logger.verbose('[Bundler] Emit hmr update...'); + // Emit an HMR update if this is not the initial bundle. if (this.hmr && !isInitialBundle) { this.hmr.emitUpdate(changedAssets); } + logger.verbose('[Bundler] Package everything up...'); + // Package everything up this.bundleHashes = await this.mainBundle.package( this, this.bundleHashes ); + logger.verbose('[Bundler] Unload any orphaned assets...'); + // Unload any orphaned assets this.unloadOrphanedAssets(); @@ -485,6 +505,8 @@ class Bundler extends EventEmitter { } async processAsset(asset, isRebuild) { + logger.verbose(`${asset.relativeName} - Start processing`); + if (isRebuild) { asset.invalidate(); if (this.cache) { @@ -493,6 +515,8 @@ class Bundler extends EventEmitter { } await this.loadAsset(asset); + + logger.verbose(`${asset.relativeName} - Done processing`); } async loadAsset(asset) { @@ -500,9 +524,11 @@ class Bundler extends EventEmitter { return; } + logger.verbose(`${asset.relativeName} - Load asset`); + if (!this.errored) { logger.status(emoji.progress, `Building ${asset.basename}...`); - logger.verbose(`Queuing ${asset.basename}...`); + logger.verbose(`${asset.relativeName} - Queuing`); } // Mark the asset processed so we don't load it twice @@ -514,19 +540,19 @@ class Bundler extends EventEmitter { let cacheMiss = false; if (!processed || asset.shouldInvalidate(processed.cacheData)) { logger.verbose( - `${!processed ? 'Cache miss,' : 'Invalidated,'} ${asset.basename}...` + `${asset.relativeName} - ${!processed ? 'Cache miss' : 'Invalidated'}` ); processed = await this.farm.run(asset.name); cacheMiss = true; } else { - logger.verbose(`Copied ${asset.basename} from cache...`); + logger.verbose(`${asset.relativeName} - Copied from cache`); } asset.buildTime = Date.now() - startTime; asset.generated = processed.generated; asset.hash = processed.hash; - logger.verbose(`Finished building ${asset.basename}...`); + logger.verbose(`${asset.relativeName} - Finished building`); // Call the delegate to get implicit dependencies let dependencies = processed.dependencies; @@ -540,6 +566,12 @@ class Bundler extends EventEmitter { // Resolve and load asset dependencies let assetDeps = await Promise.all( dependencies.map(async dep => { + logger.verbose( + `${asset.relativeName} - Getting dependency: ${Path.relative( + this.options.rootDir, + dep.name + )}` + ); if (dep.includedInParent) { // This dependency is already included in the parent's generated output, // so no need to load it. We map the name back to the parent asset so @@ -549,11 +581,19 @@ class Bundler extends EventEmitter { let assetDep = await this.resolveDep(asset, dep); if (assetDep) { logger.verbose( - `Load dependency ${assetDep.basename} of ${asset.basename}...` + `${asset.relativeName} - Load dependency: ${ + assetDep.relativeName + }` ); await this.loadAsset(assetDep); } + logger.verbose( + `${asset.relativeName} - Done loading dependency: ${ + assetDep.relativeName + }` + ); + return assetDep; } }) @@ -569,9 +609,15 @@ class Bundler extends EventEmitter { } }); + logger.verbose(`${asset.relativeName} - Dependencies loaded`); + if (this.cache && cacheMiss) { this.cache.write(asset.name, processed); + + logger.verbose(`${asset.relativeName} - Cache written`); } + + logger.verbose(`${asset.relativeName} - Done loading asset`); } createBundleTree(asset, bundle, dep, parentBundles = new Set()) {