Closed Bug 1399769 Opened 7 years ago Closed 7 years ago

Intermittent Return code: 254

Categories

(Testing :: Mochitest, defect, P5)

Product:
Testing
Component:
Mochitest
Version:
Version 3
Type:
defect

Tracking

(firefox57 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla57
Tracking Flags:
Tracking Status
firefox57 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: gbrown)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed:other])

Attachments

(1 file)

normally return 0 from runtests.py, even when tests fail
1.88 KB, patch
jmaher
: review+
Details | Diff | Splinter Review 
Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=130937615&repo=autoland

https://queue.taskcluster.net/v1/task/Kwmeoco1TNSmBI8dvRHr6w/runs/0/artifacts/public/logs/live_backing.log

[task 2017-09-14T06:41:33.686530Z] 06:41:33     INFO -  1048 INFO TEST-START | dom/xml/test/test_bug445330.html
[task 2017-09-14T06:41:33.831627Z] 06:41:33     INFO -  GECKO(3827) | MEMORY STAT | vsize 1744MB | residentFast 89MB | heapAllocated 21MB
[task 2017-09-14T06:41:33.856018Z] 06:41:33     INFO -  1049 INFO TEST-OK | dom/xml/test/test_bug445330.html | took 177ms
[task 2017-09-14T06:41:33.920955Z] 06:41:33     INFO -  1050 INFO TEST-START | dom/xml/test/test_bug691215.html
[task 2017-09-14T06:41:35.700976Z] 06:41:35     INFO -  GECKO(3827) | MEMORY STAT | vsize 1793MB | residentFast 107MB | heapAllocated 31MB
[task 2017-09-14T06:41:35.871454Z] 06:41:35     INFO -  1051 INFO TEST-OK | dom/xml/test/test_bug691215.html | took 1942ms
[task 2017-09-14T06:41:35.919765Z] 06:41:35     INFO -  1052 INFO TEST-START | dom/xml/test/test_viewport.xhtml
[task 2017-09-14T06:41:36.057031Z] 06:41:36     INFO -  GECKO(3827) | MEMORY STAT | vsize 1796MB | residentFast 109MB | heapAllocated 32MB
[task 2017-09-14T06:41:36.078004Z] 06:41:36     INFO -  1053 INFO TEST-OK | dom/xml/test/test_viewport.xhtml | took 157ms
[task 2017-09-14T06:41:36.160238Z] 06:41:36     INFO -  1054 INFO TEST-START | Shutdown
[task 2017-09-14T06:41:36.166024Z] 06:41:36     INFO -  1055 INFO Passed:  21
[task 2017-09-14T06:41:36.171522Z] 06:41:36     INFO -  1056 INFO Failed:  0
[task 2017-09-14T06:41:36.171798Z] 06:41:36     INFO -  1057 INFO Todo:    0
[task 2017-09-14T06:41:36.172039Z] 06:41:36     INFO -  1058 INFO Mode:    e10s
[task 2017-09-14T06:41:36.175968Z] 06:41:36     INFO -  1059 INFO Slowest: 1943ms - /tests/dom/xml/test/test_bug691215.html
[task 2017-09-14T06:41:36.179458Z] 06:41:36     INFO -  1060 INFO SimpleTest FINISHED
[task 2017-09-14T06:41:36.182746Z] 06:41:36     INFO -  1061 INFO TEST-INFO | Ran 1 Loops
[task 2017-09-14T06:41:36.184894Z] 06:41:36     INFO -  1062 INFO SimpleTest FINISHED
[task 2017-09-14T06:41:36.929156Z] 06:41:36     INFO -  GECKO(3827) | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2017-09-14T06:41:37.834468Z] 06:41:37     INFO -  TEST-INFO | Main app process: exit 0
[task 2017-09-14T06:41:37.836416Z] 06:41:37     INFO -  runtests.py | Application ran for: 0:00:15.969530
[task 2017-09-14T06:41:37.837615Z] 06:41:37     INFO -  zombiecheck | Reading PID log: /tmp/tmpdrqoS2pidlog
[task 2017-09-14T06:41:37.840692Z] 06:41:37     INFO -  ==> process 3827 launched child process 3848
[task 2017-09-14T06:41:37.842469Z] 06:41:37     INFO -  ==> process 3827 launched child process 3878
[task 2017-09-14T06:41:37.845338Z] 06:41:37     INFO -  zombiecheck | Checking for orphan process with PID: 3848
[task 2017-09-14T06:41:37.847039Z] 06:41:37     INFO -  zombiecheck | Checking for orphan process with PID: 3878
[task 2017-09-14T06:41:37.848760Z] 06:41:37     INFO -  Stopping web server
[task 2017-09-14T06:41:37.863073Z] 06:41:37     INFO -  Stopping web socket server
[task 2017-09-14T06:41:37.864903Z] 06:41:37     INFO -  Stopping ssltunnel
[task 2017-09-14T06:41:37.885554Z] 06:41:37     INFO -  leakcheck | refcount logging is off, so leaks can't be detected!
[task 2017-09-14T06:41:37.886778Z] 06:41:37     INFO -  runtests.py | Running tests: end.
[task 2017-09-14T06:41:37.936485Z] 06:41:37     INFO -  Buffered messages finished
[task 2017-09-14T06:41:37.936786Z] 06:41:37     INFO -  0 INFO TEST-START | Shutdown
[task 2017-09-14T06:41:37.938895Z] 06:41:37     INFO -  1 INFO Passed:  10615
[task 2017-09-14T06:41:37.939985Z] 06:41:37  WARNING -  2 INFO Failed:  1
[task 2017-09-14T06:41:37.940311Z] 06:41:37  WARNING -  One or more unittests failed.
[task 2017-09-14T06:41:37.942977Z] 06:41:37     INFO -  3 INFO Todo:    71
[task 2017-09-14T06:41:37.943390Z] 06:41:37     INFO -  4 INFO Mode:    e10s
[task 2017-09-14T06:41:37.943629Z] 06:41:37     INFO -  5 INFO SimpleTest FINISHED
[task 2017-09-14T06:41:37.943872Z] 06:41:37     INFO -  Buffered messages finished
[task 2017-09-14T06:41:37.944101Z] 06:41:37     INFO -  SUITE-END | took 959s
[task 2017-09-14T06:41:38.016929Z] 06:41:38    ERROR - Return code: 254
Mostly Linux, all mochitest.

Follows a mochitest run in which one or more tests failed. Regression from bug 1394910? Probably harmless, but annoying.
Assignee: nobody → gbrown
Whiteboard: [stockwell needswork]
Confirmed: mozharness' run_command() prints the return code from the harness as an error if it is unexpected (non-0 for mochitests).

Modify run_command() to not report this error? No - it's probably important for some situations.

Allow -2/254 explicitly for mochitests? Seems like a messy complication.

Perhaps backout 1394910 such that failed tests do not modify the script return code, and use a different mechanism for verify to detect failed tests.
Blocks: 1394910
Passing mochitest jobs are still green, and a test failure results in orange. 

https://treeherder.mozilla.org/#/jobs?repo=try&revision=f158b67919c7a6e8eafe6de940dbdefd5cc97a8c

Note that when a test fails, the return code is 0 once again.

https://public-artifacts.taskcluster.net/LvyjvGZ-TZykSlaAzeIgwA/0/public/logs/live_backing.log

[task 2017-09-14T15:37:19.403287Z] 15:37:19     INFO -  Browser Chrome Test Summary
[task 2017-09-14T15:37:19.405276Z] 15:37:19     INFO -  	Passed: 12598
[task 2017-09-14T15:37:19.407060Z] 15:37:19  WARNING -  	Failed: 2
[task 2017-09-14T15:37:19.408798Z] 15:37:19  WARNING -  One or more unittests failed.
[task 2017-09-14T15:37:19.411493Z] 15:37:19     INFO -  	Todo: 1
[task 2017-09-14T15:37:19.413177Z] 15:37:19     INFO -  	Mode: e10s
[task 2017-09-14T15:37:19.414886Z] 15:37:19     INFO -  *** End BrowserChrome Test Results ***
[task 2017-09-14T15:37:19.421660Z] 15:37:19     INFO -  Buffered messages finished
[task 2017-09-14T15:37:19.423324Z] 15:37:19     INFO -  SUITE-END | took 1440s
[task 2017-09-14T15:37:19.481541Z] 15:37:19     INFO - Return code: 0


Test verification still fails fast, as desired:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=787d914f1f4c30f7bfcdcc68ae2147d4e1a28598&filter-tier=1&filter-tier=2&filter-tier=3
Attachment #8908200 - Flags: review?(jmaher)
Attachment #8908200 - Flags: review?(jmaher) → review+
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/267e6c477d86
Do not modify runtests.py return code for failed tests; r=jmaher
Whiteboard: [stockwell needswork] → [stockwell fixed:other]
https://hg.mozilla.org/mozilla-central/rev/267e6c477d86
Status: NEW → RESOLVED
Closed: 7 years ago
status-firefox57: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla57
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: