Skip to content

Commit 420bec2

Browse files
authoredOct 29, 2018
Merge pull request #373 from scalvert/add-debug-info
Adding debug info to test isolation validation
2 parents 8d62571 + fc263a0 commit 420bec2

11 files changed

+570
-35
lines changed
 
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
import { run } from '@ember/runloop';
2+
3+
export default function getDebugInfoAvailable() {
4+
return typeof run.backburner.getDebugInfo === 'function';
5+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,145 @@
1+
const PENDING_REQUESTS = 'Pending AJAX requests';
2+
const PENDING_TEST_WAITERS = 'Pending test waiters: YES';
3+
const PENDING_TIMERS = 'Pending timers';
4+
const PENDING_SCHEDULED_ITEMS = 'Pending scheduled items';
5+
const ACTIVE_RUNLOOPS = 'Active runloops: YES';
6+
7+
export function getSummary(testCounts, leakCounts, testNames) {
8+
let leakInfo =
9+
leakCounts.length > 0
10+
? `We found the following information that may help you identify code that violated test isolation: \n
11+
${leakCounts.join('\n')}
12+
\n`
13+
: '';
14+
let summary = `TESTS ARE NOT ISOLATED\n
15+
The following ${testCounts} test(s) have one or more issues that are resulting in non-isolation (async execution is extending beyond the duration of the test):\n
16+
${testNames.join('\n')}
17+
\n
18+
${leakInfo}
19+
More information has been printed to the console. Please use that information to help in debugging.
20+
`;
21+
22+
return summary;
23+
}
24+
25+
export default class TestDebugInfoSummary {
26+
constructor() {
27+
this._testDebugInfos = [];
28+
this.fullTestNames = [];
29+
this.hasPendingRequests = false;
30+
this.hasPendingWaiters = false;
31+
this.hasRunLoop = false;
32+
this.hasPendingTimers = false;
33+
this.hasPendingScheduledQueueItems = false;
34+
this.totalPendingRequestCount = 0;
35+
this.totalPendingTimersCount = 0;
36+
this.totalPendingScheduledQueueItemCount = 0;
37+
}
38+
39+
add(testDebugInfo) {
40+
let summary = testDebugInfo.summary;
41+
42+
this._testDebugInfos.push(testDebugInfo);
43+
44+
this.fullTestNames.push(summary.fullTestName);
45+
if (summary.hasPendingRequests) {
46+
this.hasPendingRequests = true;
47+
}
48+
if (summary.hasPendingWaiters) {
49+
this.hasPendingWaiters = true;
50+
}
51+
if (summary.hasRunLoop) {
52+
this.hasRunLoop = true;
53+
}
54+
if (summary.hasPendingTimers) {
55+
this.hasPendingTimers = true;
56+
}
57+
if (summary.pendingScheduledQueueItemCount > 0) {
58+
this.hasPendingScheduledQueueItems = true;
59+
}
60+
61+
this.totalPendingRequestCount += summary.pendingRequestCount;
62+
this.totalPendingTimersCount += summary.pendingTimersCount;
63+
this.totalPendingScheduledQueueItemCount += summary.pendingScheduledQueueItemCount;
64+
}
65+
66+
get hasDebugInfo() {
67+
return this._testDebugInfos.length > 0;
68+
}
69+
70+
printToConsole(_console = console) {
71+
_console.group('Tests not isolated');
72+
73+
this._testDebugInfos.forEach(testDebugInfo => {
74+
let summary = testDebugInfo.summary;
75+
76+
_console.group(summary.fullTestName);
77+
78+
if (summary.hasPendingRequests) {
79+
_console.log(this.formatCount(PENDING_REQUESTS, summary.pendingRequestCount));
80+
}
81+
82+
if (summary.hasPendingWaiters) {
83+
_console.log(PENDING_TEST_WAITERS);
84+
}
85+
86+
if (summary.hasPendingTimers) {
87+
_console.group(this.formatCount(PENDING_TIMERS, summary.pendingTimersCount));
88+
summary.pendingTimersStackTraces.forEach(stackTrace => {
89+
_console.log(stackTrace);
90+
});
91+
_console.groupEnd();
92+
}
93+
94+
if (summary.hasPendingScheduledQueueItems) {
95+
_console.group(
96+
this.formatCount(PENDING_SCHEDULED_ITEMS, summary.pendingScheduledQueueItemCount)
97+
);
98+
summary.pendingScheduledQueueItemStackTraces.forEach(stackTrace => {
99+
_console.log(stackTrace);
100+
});
101+
_console.groupEnd();
102+
}
103+
104+
if (summary.hasRunLoop) {
105+
_console.log(ACTIVE_RUNLOOPS);
106+
}
107+
108+
_console.groupEnd();
109+
});
110+
111+
_console.groupEnd();
112+
}
113+
114+
formatForBrowser() {
115+
let leakCounts = [];
116+
117+
if (this.hasPendingRequests) {
118+
leakCounts.push(this.formatCount(PENDING_REQUESTS, this.totalPendingRequestCount));
119+
}
120+
121+
if (this.hasPendingWaiters) {
122+
leakCounts.push(PENDING_TEST_WAITERS);
123+
}
124+
125+
if (this.hasPendingTimers) {
126+
leakCounts.push(this.formatCount(PENDING_TIMERS, this.totalPendingTimersCount));
127+
}
128+
129+
if (this.hasPendingScheduledQueueItems) {
130+
leakCounts.push(
131+
this.formatCount(PENDING_SCHEDULED_ITEMS, this.totalPendingScheduledQueueItemCount)
132+
);
133+
}
134+
135+
if (this.hasRunLoop) {
136+
leakCounts.push(ACTIVE_RUNLOOPS);
137+
}
138+
139+
return getSummary(this._testDebugInfos.length, leakCounts, this.fullTestNames);
140+
}
141+
142+
formatCount(title, count) {
143+
return `${title}: ${count}`;
144+
}
145+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,63 @@
1+
/**
2+
* Encapsulates debug information for an individual test. Aggregates information
3+
* from:
4+
* - the test info provided by qunit (module & name)
5+
* - info provided by @ember/test-helper's getSettledState function
6+
* - hasPendingTimers
7+
* - hasRunLoop
8+
* - hasPendingWaiters
9+
* - hasPendingRequests
10+
* - pendingRequestCount
11+
* - info provided by backburner's getDebugInfo method (timers, schedules, and stack trace info)
12+
*/
13+
export default class TestDebugInfo {
14+
constructor(module, name, settledState, debugInfo) {
15+
this.module = module;
16+
this.name = name;
17+
this.settledState = settledState;
18+
this.debugInfo = debugInfo;
19+
}
20+
21+
get fullTestName() {
22+
return `${this.module}: ${this.name}`;
23+
}
24+
25+
get summary() {
26+
if (!this._summaryInfo) {
27+
this._summaryInfo = Object.assign(
28+
{
29+
fullTestName: this.fullTestName,
30+
},
31+
this.settledState
32+
);
33+
34+
if (this.debugInfo) {
35+
this._summaryInfo.pendingTimersCount = this.debugInfo.timers.length;
36+
this._summaryInfo.pendingTimersStackTraces = this.debugInfo.timers.map(
37+
timer => timer.stack
38+
);
39+
this._summaryInfo.pendingScheduledQueueItemCount = this.debugInfo.instanceStack
40+
.filter(q => q)
41+
.reduce((total, item) => {
42+
Object.keys(item).forEach(queueName => {
43+
total += item[queueName].length;
44+
});
45+
46+
return total;
47+
}, 0);
48+
this._summaryInfo.pendingScheduledQueueItemStackTraces = this.debugInfo.instanceStack
49+
.filter(q => q)
50+
.reduce((stacks, deferredActionQueues) => {
51+
Object.keys(deferredActionQueues).forEach(queue => {
52+
deferredActionQueues[queue].forEach(
53+
queueItem => queueItem.stack && stacks.push(queueItem.stack)
54+
);
55+
});
56+
return stacks;
57+
}, []);
58+
}
59+
}
60+
61+
return this._summaryInfo;
62+
}
63+
}

‎addon-test-support/ember-qunit/test-isolation-validation.js

+21-14
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,11 @@
11
import { run } from '@ember/runloop';
2-
import { isSettled } from '@ember/test-helpers';
2+
import { isSettled, getSettledState } from '@ember/test-helpers';
3+
import TestDebugInfo from './-internal/test-debug-info';
4+
import TestDebugInfoSummary from './-internal/test-debug-info-summary';
5+
import getDebugInfoAvailable from './-internal/get-debug-info-available';
36

4-
const TESTS_NOT_ISOLATED = [];
7+
const { backburner } = run;
8+
let nonIsolatedTests;
59

610
/**
711
* Detects if a specific test isn't isolated. A test is considered
@@ -18,8 +22,19 @@ const TESTS_NOT_ISOLATED = [];
1822
* @param {string} testInfo.name The test name
1923
*/
2024
export function detectIfTestNotIsolated({ module, name }) {
25+
nonIsolatedTests = new TestDebugInfoSummary();
26+
2127
if (!isSettled()) {
22-
TESTS_NOT_ISOLATED.push(`${module}: ${name}`);
28+
let testDebugInfo;
29+
let backburnerDebugInfo;
30+
31+
if (getDebugInfoAvailable()) {
32+
backburnerDebugInfo = backburner.getDebugInfo();
33+
}
34+
35+
testDebugInfo = new TestDebugInfo(module, name, getSettledState(), backburnerDebugInfo);
36+
37+
nonIsolatedTests.add(testDebugInfo);
2338
run.cancelTimers();
2439
}
2540
}
@@ -32,17 +47,9 @@ export function detectIfTestNotIsolated({ module, name }) {
3247
* @throws Error if tests are not isolated
3348
*/
3449
export function reportIfTestNotIsolated() {
35-
if (TESTS_NOT_ISOLATED.length > 0) {
36-
let leakyTests = TESTS_NOT_ISOLATED.slice();
37-
TESTS_NOT_ISOLATED.length = 0;
50+
if (nonIsolatedTests.hasDebugInfo) {
51+
nonIsolatedTests.printToConsole();
3852

39-
throw new Error(getMessage(leakyTests.length, leakyTests.join('\n')));
53+
throw new Error(nonIsolatedTests.formatForBrowser());
4054
}
4155
}
42-
43-
export function getMessage(testCount, testsToReport) {
44-
return `TESTS ARE NOT ISOLATED
45-
The following (${testCount}) tests have one or more of pending timers, pending AJAX requests, pending test waiters, or are still in a runloop: \n
46-
${testsToReport}
47-
`;
48-
}

‎package.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,7 @@
4747
"ember-disable-prototype-extensions": "^1.1.2",
4848
"ember-load-initializers": "^1.0.0",
4949
"ember-resolver": "^5.0.1",
50-
"ember-source": "~3.5.0",
50+
"ember-source": "3.4.5",
5151
"ember-source-channel-url": "^1.0.1",
5252
"ember-try": "^1.1.0",
5353
"eslint": "^5.8.0",
+107
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,107 @@
1+
import { module, test } from 'qunit';
2+
import TestDebugInfoSummary, { getSummary } from 'ember-qunit/-internal/test-debug-info-summary';
3+
import TestDebugInfo from 'ember-qunit/-internal/test-debug-info';
4+
import { MockConsole, getSettledState, debugInfo } from './utils/test-isolation-helpers';
5+
6+
module('TestDebugInfoSummary', function() {
7+
test('hasDebugInfo returns true if TestDebugInfos have been added', function(assert) {
8+
assert.expect(1);
9+
10+
let testDebugInfoSummary = new TestDebugInfoSummary();
11+
12+
testDebugInfoSummary.add(new TestDebugInfo('foo', 'bar', {}));
13+
testDebugInfoSummary.add(new TestDebugInfo('ding', 'bat', {}));
14+
15+
assert.ok(testDebugInfoSummary.hasDebugInfo);
16+
});
17+
18+
test('printToConsole correctly prints minimal information', function(assert) {
19+
assert.expect(1);
20+
21+
let mockConsole = new MockConsole();
22+
let testDebugInfoSummary = new TestDebugInfoSummary();
23+
24+
testDebugInfoSummary.add(new TestDebugInfo('foo', 'bar', getSettledState()));
25+
testDebugInfoSummary.add(new TestDebugInfo('ding', 'bat', getSettledState()));
26+
27+
testDebugInfoSummary.printToConsole(mockConsole);
28+
29+
assert.deepEqual(
30+
mockConsole.toString(),
31+
`Tests not isolated
32+
foo: bar
33+
ding: bat`
34+
);
35+
});
36+
37+
test('printToConsole correctly prints all information', function(assert) {
38+
assert.expect(1);
39+
40+
let mockConsole = new MockConsole();
41+
let testDebugInfoSummary = new TestDebugInfoSummary();
42+
43+
testDebugInfoSummary.add(
44+
new TestDebugInfo('foo', 'bar', getSettledState(true, true), debugInfo)
45+
);
46+
testDebugInfoSummary.add(
47+
new TestDebugInfo('ding', 'bat', getSettledState(false, true, false, true, 2), debugInfo)
48+
);
49+
50+
testDebugInfoSummary.printToConsole(mockConsole);
51+
52+
assert.deepEqual(
53+
mockConsole.toString(),
54+
`Tests not isolated
55+
foo: bar
56+
Pending timers: 2
57+
STACK
58+
STACK
59+
Active runloops: YES
60+
ding: bat
61+
Pending AJAX requests: 2
62+
Active runloops: YES`
63+
);
64+
});
65+
66+
test('formatForBrowser correctly prints minimal information', function(assert) {
67+
assert.expect(1);
68+
69+
let testDebugInfoSummary = new TestDebugInfoSummary();
70+
71+
testDebugInfoSummary.add(new TestDebugInfo('foo', 'bar', getSettledState()));
72+
testDebugInfoSummary.add(new TestDebugInfo('ding', 'bat', getSettledState()));
73+
74+
let browserOutput = testDebugInfoSummary.formatForBrowser();
75+
76+
assert.equal(browserOutput, getSummary(2, 0, ['foo: bar', 'ding: bat']));
77+
});
78+
79+
test('formatForBrowser correctly prints all information', function(assert) {
80+
assert.expect(1);
81+
82+
let testDebugInfoSummary = new TestDebugInfoSummary();
83+
84+
testDebugInfoSummary.add(
85+
new TestDebugInfo('foo', 'bar', getSettledState(true, true), debugInfo)
86+
);
87+
testDebugInfoSummary.add(
88+
new TestDebugInfo('ding', 'bat', getSettledState(false, true, false, true, 2), debugInfo)
89+
);
90+
91+
let browserOutput = testDebugInfoSummary.formatForBrowser();
92+
93+
assert.equal(
94+
browserOutput,
95+
getSummary(
96+
2,
97+
[
98+
'Pending AJAX requests: 2',
99+
'Pending timers: 4',
100+
'Pending scheduled items: 4',
101+
'Active runloops: YES',
102+
],
103+
['foo: bar', 'ding: bat']
104+
)
105+
);
106+
});
107+
});

0 commit comments

Comments
 (0)