CI builds sometimes only run a subset of tests #2249
Comments
Update the software used to run tests in CI. This _may_ help with #2249.
|
I noticed this in the CI logs for a recent master build. Probably unrelated, but I'll note it anyway: |
|
Example of a build of the Looking through the recent builds list on Jenkins (29) builds, this issue happened in two of them: #1986 and #1982. It would be interesting to look at the Chrome browser logs for those builds, but unfortunately we only keep the one for the most recent build. |
During CI runs, but not local development, log which individual tests have executed. This may help with debugging #2249.
|
We updated the version of Alpine that is used on Jenkins CI and I don't think we've seen the problem since there, although Lyza did report that it happened on her system. #2263 has modified the CI build so that it logs which tests have executed, which should help debugging if the issue happens again. Reproducing the issue on my system may be more difficult now because I updated my laptop and the new one is faster. One thing I probably will try before closing this as "maybe fixed - wait until it happens again so I can continue debugging" is to write a script that just runs the test suite in a loop many times and checking whether the issue occurred. It may also be worth checking to see if it happens in an environment where the system is resource constrained (eg. in a Docker container with reduced CPU limits). |
|
I was able to reproduce this issue locally with the following script: import re
import subprocess
import sys
max_iterations = 100
for i in range(0, max_iterations):
print(f"Running test iteration {i+1} of {max_iterations}")
proc = subprocess.run(
"node_modules/.bin/gulp test",
shell=True,
stdout=subprocess.PIPE,
check=True,
)
stdout = proc.stdout.decode()
tests_run_match = re.search("TOTAL: ([0-9]+) SUCCESS", stdout)
if not tests_run_match:
print(f"Tests failed on run {i}")
print(stdout)
sys.exit(1)
expected_tests = 2439
tests_run = int(tests_run_match.group(1))
if tests_run < expected_tests:
print(f"Only ran {tests_run} instead of {expected_tests}")
print(stdout)
sys.exit(1)Output: |
Add a script to assist with debugging #2249 by running the test suite repeatedly and checking the output.
|
By adding logging to By modifying the The function name in the browserify bundle is unfortunately minified and the bundle isn't normally present on the file system after the test runs. However by modifying Navigating to the line and column specified on this line: Finds that the timeout is being cleared from this minified function: After looking around the surrounding code to figure out what package it is probably from, I think it is the Timer IDs are integers and in the case of sinon's fake timers they are just allocated sequentially from 1. Timer IDs allocated by the native |
|
It looks like In sinon, it seems that |
Add a script to assist with debugging #2249 by running the test suite repeatedly and checking the output.
|
The problem where only a subset of the tests run but the test suite exits without any apparent failure can be reproduced on my system using a test which triggers an uncaught exception some time after the test has run: diff --git a/src/sidebar/util/test/dom-test.js b/src/sidebar/util/test/dom-test.js
index 7d4511d50..29502d410 100644
--- a/src/sidebar/util/test/dom-test.js
+++ b/src/sidebar/util/test/dom-test.js
@@ -24,6 +24,14 @@ describe('sidebar/util/dom', () => {
});
});
+ describe('TESTING', () => {
+ it('should blow up', () => {
+ setTimeout(() => {
+ throw new Error('Fail!');
+ }, 0);
+ });
+ });
+
describe('listen', () => {
const createFakeElement = () => ({
addEventListener: sinon.stub(),And then running The output in this contains no hint of an error: But if the broken test is commented out, the output is: |
|
The way our test environment works is that Karma loads all the test code into a mostly empty web page and then runs Mocha using a test-runner adapter provided by the karma-mocha package. When karma-mocha runs Mocha, it sets up a custom reporter that translates Mocha test events into Karma test runner events. By adding some instrumentation to the
|
|
Looking at hypothesis/karma-mocha@25f9a6f it seems that karma-mocha expects that uncaught exceptions will always be followed by a "test end" event, which it seems is not happening when an uncaught exception is thrown in-between tests after the most recent test completed successfully. At this point I'm not clear on whether karma-mocha's expectations about a "fail" event always being followed by a "test end" event are wrong, or whether the behavior of mocha in this situation is incorrect. |
Add a script to assist with debugging #2249 by running the test suite repeatedly and checking that the tests completed successfully and that the expected number of tests were run.
Add a script to assist with debugging #2249 by running the test suite repeatedly and checking that the tests completed successfully and that the expected number of tests were run.
Due to an issue with the interaction between mocha and karma-mocha [1], uncaught exceptions or promise rejections that occur in between tests can cause the test run to stop immediately yet incorrectly report that all tests executed succesfully and hence CI runs / Jenkins builds incorrectly report their status. This commit works around the issue until the problem is resolved in mocha / karma-mocha by adding an `afterEach` hook which will re-throw any uncaught exceptions and ensure that mocha notices them and reports the failure correctly to Karma. [1] See comments on #2249
Fix a test that was failing but failing in a way that went unreported previously due to a combination of it occurring after the test function returned because of a missing `await` call and because of the issue with uncaught exceptions between tests described in #2249. This test was failing but the failure was only reported after the test function returned due to a missing `await`.
Due to an issue with the interaction between mocha and karma-mocha [1], uncaught exceptions or promise rejections that occur in between tests can cause the test run to stop immediately yet incorrectly report that all tests executed succesfully and hence CI runs / Jenkins builds incorrectly report their status. This commit works around the issue until the problem is resolved in mocha / karma-mocha by adding an `afterEach` hook which will re-throw any uncaught exceptions and ensure that mocha notices them and reports the failure correctly to Karma. [1] See comments on #2249
Fix a test that was failing but failing in a way that went unreported previously due to a combination of it occurring after the test function returned because of a missing `await` call and because of the issue with uncaught exceptions between tests described in #2249. This test was failing but the failure was only reported after the test function returned due to a missing `await`.
|
Update: The problem is now partly addressed by a workaround. The issue that causes the uncaught exceptions to occur in between tests still exists, but at least the test run will fail now rather than incorrectly reporting that the tests all ran successfully. |
|
I haven't seen this issue happen in some time, so I'm going to close this for now. |
We've seen an issue in CI, and Lyza and myself have also experienced it locally too, where builds occasionally "succeed" but only run a fraction (typically 300-500 it seems) of the tests.
When this happens, codecov will typically report a sudden unexpected drop in code coverage.
Original report: #2244 (comment)
The text was updated successfully, but these errors were encountered: