Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

better debug output #4236

Merged
merged 1 commit into from Apr 24, 2020
Merged

better debug output #4236

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
9 changes: 7 additions & 2 deletions bin/mocha
View file
Open in desktop
Expand Up @@ -34,7 +34,7 @@ debug('loaded opts', opts);
*/
const disableTimeouts = value => {
if (impliesNoTimeouts(value)) {
debug(`option "${value}" disabled timeouts`);
debug('option %s disabled timeouts', value);
mochaArgs.timeout = 0;
delete mochaArgs.timeouts;
delete mochaArgs.t;
Expand Down Expand Up @@ -108,7 +108,11 @@ if (Object.keys(nodeArgs).length) {
unparse(mochaArgs, {alias: aliases})
);

boneskull marked this conversation as resolved.
Show resolved Hide resolved
debug(`exec ${process.execPath} w/ args:`, args);
debug(
'forking child process via command: %s %s',
process.execPath,
args.join(' ')
);

const proc = spawn(process.execPath, args, {
stdio: 'inherit'
Expand All @@ -130,5 +134,6 @@ if (Object.keys(nodeArgs).length) {
proc.kill('SIGTERM'); // if that didn't work, we're probably in an infinite loop, so make it die.
});
} else {
debug('running Mocha in-process');
require('../lib/cli/cli').main(unparse(mochaArgs, {alias: aliases}));
}
8 changes: 4 additions & 4 deletions lib/cli/config.js
View file
Open in desktop
Expand Up @@ -42,11 +42,11 @@ const parsers = (exports.parsers = {
js: filepath => {
const cwdFilepath = path.resolve(filepath);
try {
debug(`parsers: load using cwd-relative path: "${cwdFilepath}"`);
debug('parsers: load using cwd-relative path: "%s"', cwdFilepath);
return require(cwdFilepath);
} catch (err) {
if (isModuleNotFoundError(err)) {
debug(`parsers: retry load as module-relative path: "${filepath}"`);
debug('parsers: retry load as module-relative path: "%s"', filepath);
return require(filepath);
} else {
throw err; // rethrow
Expand All @@ -69,7 +69,7 @@ const parsers = (exports.parsers = {
*/
exports.loadConfig = filepath => {
let config = {};
debug(`loadConfig: "${filepath}"`);
debug('loadConfig: trying to parse config at %s', filepath);

const ext = path.extname(filepath);
try {
boneskull marked this conversation as resolved.
Show resolved Hide resolved
Expand All @@ -95,7 +95,7 @@ exports.loadConfig = filepath => {
exports.findConfig = (cwd = process.cwd()) => {
const filepath = findUp.sync(exports.CONFIG_FILES, {cwd});
if (filepath) {
debug(`findConfig: found "${filepath}"`);
debug('findConfig: found config file %s', filepath);
}
return filepath;
};
6 changes: 3 additions & 3 deletions lib/cli/options.js
View file
Open in desktop
Expand Up @@ -178,16 +178,16 @@ const loadPkgRc = (args = {}) => {
try {
boneskull marked this conversation as resolved.
Show resolved Hide resolved
const pkg = JSON.parse(fs.readFileSync(filepath, 'utf8'));
if (pkg.mocha) {
debug(`'mocha' prop of package.json parsed:`, pkg.mocha);
debug('`mocha` prop of package.json parsed: %O', pkg.mocha);
result = pkg.mocha;
} else {
debug(`no config found in ${filepath}`);
debug('no config found in %s', filepath);
}
} catch (err) {
if (args.package) {
throw new Error(`Unable to read/parse ${filepath}: ${err}`);
}
debug(`failed to read default package.json at ${filepath}; ignoring`);
debug('failed to read default package.json at %s; ignoring', filepath);
}
}
return result;
Expand Down
6 changes: 3 additions & 3 deletions lib/cli/run-helpers.js
View file
Open in desktop
Expand Up @@ -82,10 +82,10 @@ exports.handleRequires = (requires = []) => {
let modpath = mod;
if (fs.existsSync(mod, {cwd}) || fs.existsSync(`${mod}.js`, {cwd})) {
modpath = path.resolve(mod);
debug(`resolved ${mod} to ${modpath}`);
debug('resolved %s to %s', mod, modpath);
}
require(modpath);
debug(`loaded require "${mod}"`);
debug('loaded required module "%s"', mod);
});
};

Expand All @@ -101,7 +101,7 @@ exports.handleRequires = (requires = []) => {
*/
const singleRun = async (mocha, {exit}, fileCollectParams) => {
const files = collectFiles(fileCollectParams);
debug('running tests with files', files);
debug('single run with %d file(s)', files.length);
mocha.files = files;

await mocha.loadFilesAsync();
Expand Down
40 changes: 29 additions & 11 deletions lib/runner.js
View file
Open in desktop
Expand Up @@ -173,7 +173,7 @@ inherits(Runner, EventEmitter);
* @return {Runner} Runner instance.
*/
Runner.prototype.grep = function(re, invert) {
debug('grep %s', re);
debug('grep(): setting to %s', re);
this._grep = re;
this._invert = invert;
this.total = this.grepTotal(this.suite);
Expand Down Expand Up @@ -238,7 +238,7 @@ Runner.prototype.globals = function(arr) {
if (!arguments.length) {
return this._globals;
}
debug('globals %j', arr);
debug('globals(): setting to %O', arr);
this._globals = this._globals.concat(arr);
return this;
};
Expand Down Expand Up @@ -718,9 +718,10 @@ Runner.prototype.runSuite = function(suite, fn) {
var self = this;
var total = this.grepTotal(suite);

debug('run suite %s', suite.fullTitle());
debug('runSuite(): running %s', suite.fullTitle());

if (!total || (self.failures && suite._bail)) {
debug('runSuite(): bailing');
return fn();
}

Expand Down Expand Up @@ -791,17 +792,19 @@ Runner.prototype.runSuite = function(suite, fn) {
*/
Runner.prototype.uncaught = function(err) {
if (err instanceof Pending) {
debug('uncaught(): caught a Pending');
return;
}
// browser does not exit script when throwing in global.onerror()
if (this.allowUncaught && !process.browser) {
debug('uncaught(): bubbling exception due to --allow-uncaught');
throw err;
}

if (err) {
debug('uncaught exception %O', err);
debug('uncaught(): got truthy exception %O', err);
} else {
debug('uncaught undefined/falsy exception');
debug('uncaught(): undefined/falsy exception');
err = createInvalidExceptionError(
'Caught falsy/undefined exception which would otherwise be uncaught. No stack trace found; try a debugger',
err
Expand All @@ -810,19 +813,23 @@ Runner.prototype.uncaught = function(err) {

if (!isError(err)) {
err = thrown2Error(err);
debug('uncaught(): converted "error" %o to Error', err);
}
err.uncaught = true;

var runnable = this.currentRunnable;

if (!runnable) {
runnable = new Runnable('Uncaught error outside test suite');
debug('uncaught(): no current Runnable; created a phony one');
runnable.parent = this.suite;

if (this.started) {
debug('uncaught(): failing gracefully');
this.fail(runnable, err);
} else {
// Can't recover from this failure
debug('uncaught(): test run has not yet started; unrecoverable');
this.emit(constants.EVENT_RUN_BEGIN);
this.fail(runnable, err);
this.emit(constants.EVENT_RUN_END);
Expand All @@ -834,9 +841,11 @@ Runner.prototype.uncaught = function(err) {
runnable.clearTimeout();

if (runnable.isFailed()) {
debug('uncaught(): Runnable has already failed');
// Ignore error if already failed
return;
} else if (runnable.isPending()) {
debug('uncaught(): pending Runnable wound up failing!');
// report 'pending test' retrospectively as failed
this.fail(runnable, err, true);
return;
Expand All @@ -845,10 +854,11 @@ Runner.prototype.uncaught = function(err) {
// we cannot recover gracefully if a Runnable has already passed
// then fails asynchronously
if (runnable.isPassed()) {
debug('uncaught(): Runnable has already passed; bailing gracefully');
this.fail(runnable, err);
this.abort();
} else {
debug(runnable);
debug('uncaught(): forcing Runnable to complete with Error');
return runnable.callback(err);
}
};
Expand Down Expand Up @@ -884,34 +894,41 @@ Runner.prototype.run = function(fn) {
}

function start() {
debug('run(): starting');
// If there is an `only` filter
if (rootSuite.hasOnly()) {
rootSuite.filterOnly();
debug('run(): filtered exclusive Runnables');
}
self.started = true;
if (self._delay) {
self.emit(constants.EVENT_DELAY_END);
debug('run(): "delay" ended');
}
debug('run(): emitting %s', constants.EVENT_RUN_BEGIN);
self.emit(constants.EVENT_RUN_BEGIN);
debug('run(): emitted %s', constants.EVENT_RUN_BEGIN);

self.runSuite(rootSuite, function() {
debug('finished running');
debug(
'run(): root suite completed; emitting %s',
constants.EVENT_RUN_END
);
self.emit(constants.EVENT_RUN_END);
debug('run(): emitted %s', constants.EVENT_RUN_END);
});
}

debug(constants.EVENT_RUN_BEGIN);

// references cleanup to avoid memory leaks
this.on(constants.EVENT_SUITE_END, function(suite) {
suite.cleanReferences();
});

// callback
this.on(constants.EVENT_RUN_END, function() {
debug(constants.EVENT_RUN_END);
process.removeListener('uncaughtException', uncaught);
process.on('uncaughtException', self.uncaughtEnd);
debug('run(): emitted %s', constants.EVENT_RUN_END);
fn(self.failures);
});

Expand All @@ -924,6 +941,7 @@ Runner.prototype.run = function(fn) {
// might be nice to debounce some dots while we wait.
this.emit(constants.EVENT_DELAY_BEGIN, rootSuite);
rootSuite.once(EVENT_ROOT_SUITE_RUN, start);
debug('run(): waiting for green light due to --delay');
} else {
Runner.immediately(function() {
start();
Expand All @@ -941,7 +959,7 @@ Runner.prototype.run = function(fn) {
* @return {Runner} Runner instance.
*/
Runner.prototype.abort = function() {
debug('aborting');
debug('abort(): aborting');
this._abort = true;

return this;
Expand Down