Added the ability to associate trace information with failing specs

This is meant to aid in debugging failures, particularly intermittent
failures, in cases where interactive debugging or console.log aren't
suitable.
This commit is contained in:
Steve Gravrock
2021-09-25 16:07:33 -07:00
parent ef981bb794
commit 7a289f1de7
12 changed files with 447 additions and 7 deletions

View File

@@ -423,9 +423,53 @@ jasmineRequire.HtmlReporter = function(j$) {
);
}
if (result.trace) {
messages.appendChild(traceTable(result.trace));
}
return failure;
}
function traceTable(trace) {
var tbody = createDom('tbody');
trace.forEach(function(entry) {
tbody.appendChild(
createDom(
'tr',
{},
createDom('td', {}, entry.timestamp.toString()),
createDom('td', {}, entry.message)
)
);
});
return createDom(
'div',
{ className: 'jasmine-trace' },
createDom(
'div',
{ className: 'jasmine-trace-header' },
'Trace information'
),
createDom(
'table',
{},
createDom(
'thead',
{},
createDom(
'tr',
{},
createDom('th', {}, 'Time (ms)'),
createDom('th', {}, 'Message')
)
),
tbody
)
);
}
function summaryList(resultsTree, domParent) {
var specListNode;
for (var i = 0; i < resultsTree.children.length; i++) {

View File

@@ -268,4 +268,17 @@ body {
border: 1px solid #ddd;
background: white;
white-space: pre;
}
.jasmine_html-reporter .jasmine-trace {
margin: 5px 0 0 0;
padding: 5px;
color: #666;
border: 1px solid #ddd;
background: white;
}
.jasmine_html-reporter .jasmine-trace table {
border-spacing: 0;
}
.jasmine_html-reporter .jasmine-trace table, .jasmine_html-reporter .jasmine-trace th, .jasmine_html-reporter .jasmine-trace td {
border: 1px solid #ddd;
}

View File

@@ -589,6 +589,22 @@ getJasmineRequireObj().base = function(j$, jasmineGlobal) {
putativeSpy.calls instanceof j$.CallTracker
);
};
/**
* Logs a message for use in debugging. If the spec fails, trace messages
* will be included in the {@link SpecResult|result} passed to the
* reporter's specDone method.
*
* This method should be called only when a spec (including any associated
* beforeEach or afterEach functions) is running.
* @function
* @name jasmine.trace
* @since 3.10.0
* @param {String} msg - The message to log
*/
j$.trace = function(msg) {
j$.getEnv().trace(msg);
};
};
getJasmineRequireObj().util = function(j$) {
@@ -823,8 +839,9 @@ getJasmineRequireObj().Spec = function(j$) {
* @property {String} status - Once the spec has completed, this string represents the pass/fail status of this spec.
* @property {number} duration - The time in ms used by the spec execution, including any before/afterEach.
* @property {Object} properties - User-supplied properties, if any, that were set using {@link Env#setSpecProperty}
* @property {TraceEntry[]|null} trace - Trace messages, if any, that were logged using {@link Env#trace} during a failing spec.
* @since 2.0.0
x */
*/
this.result = {
id: this.id,
description: this.description,
@@ -834,7 +851,8 @@ x */
deprecationWarnings: [],
pendingReason: '',
duration: null,
properties: null
properties: null,
trace: null
};
}
@@ -879,6 +897,11 @@ x */
self.queueableFn.fn = null;
self.result.status = self.status(excluded, failSpecWithNoExp);
self.result.duration = self.timer.elapsed();
if (self.result.status !== 'failed') {
self.result.trace = null;
}
self.resultCallback(self.result, done);
}
};
@@ -990,6 +1013,20 @@ x */
);
};
Spec.prototype.trace = function(msg) {
if (!this.result.trace) {
this.result.trace = [];
}
/**
* @typedef TraceEntry
* @property {String} message - The message that was passed to {@link Env#trace}.
* @property {number} timestamp - The time when the entry was added, in
* milliseconds from the spec's start time
*/
this.result.trace.push({ message: msg, timestamp: this.timer.elapsed() });
};
var extractCustomPendingMessage = function(e) {
var fullMessage = e.toString(),
boilerplateStart = fullMessage.indexOf(Spec.pendingSpecExceptionMessage),
@@ -2383,6 +2420,16 @@ getJasmineRequireObj().Env = function(j$) {
currentSuite().setSuiteProperty(key, value);
};
this.trace = function(msg) {
var maybeSpec = currentRunnable();
if (!maybeSpec || !maybeSpec.trace) {
throw new Error("'trace' was called when there was no current spec");
}
maybeSpec.trace(msg);
};
this.expect = function(actual) {
if (!currentRunnable()) {
throw new Error(

View File

@@ -228,7 +228,8 @@ describe('Spec', function() {
deprecationWarnings: [],
pendingReason: '',
duration: jasmine.any(Number),
properties: null
properties: null,
trace: null
},
'things'
);
@@ -516,4 +517,110 @@ describe('Spec', function() {
args.cleanupFns[0].fn();
expect(resultCallback.calls.first().args[0].failedExpectations).toEqual([]);
});
describe('#trace', function() {
it('adds the messages to the result', function() {
var timer = jasmine.createSpyObj('timer', ['start', 'elapsed']),
spec = new jasmineUnderTest.Spec({
queueableFn: {
fn: function() {}
},
queueRunnerFactory: function() {},
timer: timer
}),
t1 = 123,
t2 = 456;
spec.execute();
expect(spec.result.trace).toBeNull();
timer.elapsed.and.returnValue(t1);
spec.trace('msg 1');
expect(spec.result.trace).toEqual([{ message: 'msg 1', timestamp: t1 }]);
timer.elapsed.and.returnValue(t2);
spec.trace('msg 2');
expect(spec.result.trace).toEqual([
{ message: 'msg 1', timestamp: t1 },
{ message: 'msg 2', timestamp: t2 }
]);
});
describe('When the spec passes', function() {
it('omits the messages from the reported result', function() {
var resultCallback = jasmine.createSpy('resultCallback'),
spec = new jasmineUnderTest.Spec({
queueableFn: {
fn: function() {}
},
resultCallback: resultCallback,
queueRunnerFactory: function(config) {
spec.trace('msg');
config.cleanupFns.forEach(function(fn) {
fn.fn();
});
config.onComplete(false);
}
});
spec.execute(function() {});
expect(resultCallback).toHaveBeenCalledWith(
jasmine.objectContaining({ trace: null }),
undefined
);
});
it('removes the messages to save memory', function() {
var resultCallback = jasmine.createSpy('resultCallback'),
spec = new jasmineUnderTest.Spec({
queueableFn: {
fn: function() {}
},
resultCallback: resultCallback,
queueRunnerFactory: function(config) {
spec.trace('msg');
config.cleanupFns.forEach(function(fn) {
fn.fn();
});
config.onComplete(false);
}
});
spec.execute(function() {});
expect(resultCallback).toHaveBeenCalled();
expect(spec.result.trace).toBeNull();
});
});
describe('When the spec fails', function() {
it('includes the messages in the reported result', function() {
var resultCallback = jasmine.createSpy('resultCallback'),
timer = jasmine.createSpyObj('timer', ['start', 'elapsed']),
spec = new jasmineUnderTest.Spec({
queueableFn: {
fn: function() {}
},
resultCallback: resultCallback,
queueRunnerFactory: function(config) {
spec.trace('msg');
spec.onException(new Error('nope'));
config.cleanupFns.forEach(function(fn) {
fn.fn();
});
config.onComplete(true);
},
timer: timer
}),
timestamp = 12345;
timer.elapsed.and.returnValue(timestamp);
spec.execute(function() {});
expect(resultCallback).toHaveBeenCalledWith(
jasmine.objectContaining({
trace: [{ message: 'msg', timestamp: timestamp }]
}),
undefined
);
});
});
});
});

View File

@@ -186,4 +186,12 @@ describe('base helpers', function() {
});
});
});
describe('trace', function() {
it("forwards to the current env's trace function", function() {
spyOn(jasmineUnderTest.getEnv(), 'trace');
jasmineUnderTest.trace('a message');
expect(jasmineUnderTest.getEnv().trace).toHaveBeenCalledWith('a message');
});
});
});

View File

@@ -3234,4 +3234,87 @@ describe('Env integration', function() {
});
});
});
it('sends traces to the reporter when the spec fails', function(done) {
var reporter = jasmine.createSpyObj('reporter', ['specDone']),
startTime,
endTime;
env.addReporter(reporter);
env.configure({ random: false });
env.it('fails', function() {
startTime = new Date().getTime();
env.trace('message 1');
env.trace('message 2');
env.expect(1).toBe(2);
endTime = new Date().getTime();
});
env.it('passes', function() {
env.trace('message that should not be reported');
});
env.execute(null, function() {
function numberInRange(min, max) {
return {
asymmetricMatch: function(compareTo) {
return compareTo >= min && compareTo <= max;
},
jasmineToString: function(pp) {
return '<number from ' + min + ' to ' + max + ' inclusive>';
}
};
}
var duration;
expect(reporter.specDone).toHaveBeenCalledTimes(2);
duration = reporter.specDone.calls.argsFor(0)[0].duration;
expect(reporter.specDone.calls.argsFor(0)[0]).toEqual(
jasmine.objectContaining({
trace: [
{
timestamp: numberInRange(0, duration),
message: 'message 1'
},
{
timestamp: numberInRange(0, duration),
message: 'message 2'
}
]
})
);
expect(reporter.specDone.calls.argsFor(1)[0].trace).toBeFalsy();
done();
});
});
it('reports an error when trace is used when a spec is not running', function(done) {
var reporter = jasmine.createSpyObj('reporter', ['suiteDone']);
env.describe('a suite', function() {
env.beforeAll(function() {
env.trace('a message');
});
env.it('a spec', function() {});
});
env.addReporter(reporter);
env.execute(null, function() {
expect(reporter.suiteDone).toHaveBeenCalledWith(
jasmine.objectContaining({
failedExpectations: [
jasmine.objectContaining({
message: jasmine.stringContaining(
"'trace' was called when there was no current spec"
)
})
]
})
);
done();
});
});
});

View File

@@ -1339,6 +1339,23 @@ describe('HtmlReporter', function() {
}
]
};
var failingSpecResultWithTrace = {
id: 567,
status: 'failed',
description: 'a failing spec',
fullName: 'a suite inner suite a failing spec',
passedExpectations: [],
failedExpectations: [
{
message: 'a failure message',
stack: 'a stack trace'
}
],
trace: [
{ timestamp: 123, message: 'msg 1' },
{ timestamp: 456, message: 'msg 1' }
]
};
var passingSuiteResult = {
id: 1,
@@ -1356,18 +1373,20 @@ describe('HtmlReporter', function() {
reporter.suiteDone(passingSuiteResult);
reporter.suiteDone(failingSuiteResult);
reporter.suiteDone(passingSuiteResult);
reporter.specStarted(failingSpecResultWithTrace);
reporter.specDone(failingSpecResultWithTrace);
reporter.jasmineDone({});
});
it('reports the specs counts', function() {
var alertBar = container.querySelector('.jasmine-alert .jasmine-bar');
expect(alertBar.innerHTML).toMatch(/2 specs, 2 failure/);
expect(alertBar.innerHTML).toMatch(/3 specs, 3 failures/);
});
it('reports failure messages and stack traces', function() {
var specFailures = container.querySelector('.jasmine-failures');
expect(specFailures.childNodes.length).toEqual(2);
expect(specFailures.childNodes.length).toEqual(3);
var specFailure = specFailures.childNodes[0];
expect(specFailure.getAttribute('class')).toMatch(/jasmine-failed/);
@@ -1408,6 +1427,18 @@ describe('HtmlReporter', function() {
expect(suiteStackTrace.innerHTML).toEqual('a stack trace');
});
it('reports traces when present', function() {
var specFailure = container.querySelectorAll(
'.jasmine-spec-detail.jasmine-failed'
)[2],
trace = specFailure.querySelector('.jasmine-trace table'),
rows;
expect(trace).toBeTruthy();
rows = trace.querySelectorAll('tbody tr');
expect(rows.length).toEqual(2);
});
it('provides links to focus on a failure and each containing suite', function() {
var description = container.querySelector(
'.jasmine-failures .jasmine-description'

View File

@@ -1318,6 +1318,16 @@ getJasmineRequireObj().Env = function(j$) {
currentSuite().setSuiteProperty(key, value);
};
this.trace = function(msg) {
var maybeSpec = currentRunnable();
if (!maybeSpec || !maybeSpec.trace) {
throw new Error("'trace' was called when there was no current spec");
}
maybeSpec.trace(msg);
};
this.expect = function(actual) {
if (!currentRunnable()) {
throw new Error(

View File

@@ -68,8 +68,9 @@ getJasmineRequireObj().Spec = function(j$) {
* @property {String} status - Once the spec has completed, this string represents the pass/fail status of this spec.
* @property {number} duration - The time in ms used by the spec execution, including any before/afterEach.
* @property {Object} properties - User-supplied properties, if any, that were set using {@link Env#setSpecProperty}
* @property {TraceEntry[]|null} trace - Trace messages, if any, that were logged using {@link Env#trace} during a failing spec.
* @since 2.0.0
x */
*/
this.result = {
id: this.id,
description: this.description,
@@ -79,7 +80,8 @@ x */
deprecationWarnings: [],
pendingReason: '',
duration: null,
properties: null
properties: null,
trace: null
};
}
@@ -124,6 +126,11 @@ x */
self.queueableFn.fn = null;
self.result.status = self.status(excluded, failSpecWithNoExp);
self.result.duration = self.timer.elapsed();
if (self.result.status !== 'failed') {
self.result.trace = null;
}
self.resultCallback(self.result, done);
}
};
@@ -235,6 +242,20 @@ x */
);
};
Spec.prototype.trace = function(msg) {
if (!this.result.trace) {
this.result.trace = [];
}
/**
* @typedef TraceEntry
* @property {String} message - The message that was passed to {@link Env#trace}.
* @property {number} timestamp - The time when the entry was added, in
* milliseconds from the spec's start time
*/
this.result.trace.push({ message: msg, timestamp: this.timer.elapsed() });
};
var extractCustomPendingMessage = function(e) {
var fullMessage = e.toString(),
boilerplateStart = fullMessage.indexOf(Spec.pendingSpecExceptionMessage),

View File

@@ -420,4 +420,20 @@ getJasmineRequireObj().base = function(j$, jasmineGlobal) {
putativeSpy.calls instanceof j$.CallTracker
);
};
/**
* Logs a message for use in debugging. If the spec fails, trace messages
* will be included in the {@link SpecResult|result} passed to the
* reporter's specDone method.
*
* This method should be called only when a spec (including any associated
* beforeEach or afterEach functions) is running.
* @function
* @name jasmine.trace
* @since 3.10.0
* @param {String} msg - The message to log
*/
j$.trace = function(msg) {
j$.getEnv().trace(msg);
};
};

View File

@@ -392,9 +392,53 @@ jasmineRequire.HtmlReporter = function(j$) {
);
}
if (result.trace) {
messages.appendChild(traceTable(result.trace));
}
return failure;
}
function traceTable(trace) {
var tbody = createDom('tbody');
trace.forEach(function(entry) {
tbody.appendChild(
createDom(
'tr',
{},
createDom('td', {}, entry.timestamp.toString()),
createDom('td', {}, entry.message)
)
);
});
return createDom(
'div',
{ className: 'jasmine-trace' },
createDom(
'div',
{ className: 'jasmine-trace-header' },
'Trace information'
),
createDom(
'table',
{},
createDom(
'thead',
{},
createDom(
'tr',
{},
createDom('th', {}, 'Time (ms)'),
createDom('th', {}, 'Message')
)
),
tbody
)
);
}
function summaryList(resultsTree, domParent) {
var specListNode;
for (var i = 0; i < resultsTree.children.length; i++) {

View File

@@ -388,4 +388,20 @@ body {
background: white;
white-space: pre;
}
.jasmine-trace {
margin: 5px 0 0 0;
padding: 5px;
color: $light-text-color;
border: 1px solid #ddd;
background: white;
table {
border-spacing: 0;
}
table, th, td {
border: 1px solid #ddd;
}
}
}