1236378 - Test fails, but does not specify which test, only "Tests exited with return code 2: harness failures"

Status: RESOLVED FIXED

(Testing Graveyard :: JSMarionette, defect)

Description

[Michael Henretty [:mikehenrty][:mhenretty]]

We have been seeing test failures on treeherder where the failure is not reported in the Failure Summary, and so the correct test file cannot be associated with the corresponding intermittent bug. Many of these failures get wrongly associated to bug 1174901. Looking at one of these particular failures [1], it seems that the screenshot base64 output gets intermingled with the stacktrace. I wonder if that has something to do with it.

https://treeherder.mozilla.org/logviewer.html#?job_id=2988639&repo=mozilla-central

Comment 1

[Phil Ringnalda (:philor)]

Certainly is in that case, since the end of the first chunk of screenshot is "TEST-UNEXPECTED-FAIL | apps/system/test/marionette/browser_video_test.js | Video Confirm video playback" which would be a perfectly starrable if insufficiently precise failure message if it was at the start of a line instead of jammed into the end, and also for crashes like https://treeherder.mozilla.org/logviewer.html#?job_id=19168072&repo=mozilla-inbound though there there's also the subsequent failure to run stackwalk.

So at least three dependent bugs: the screenshot shouldn't be intermingled with other output; timeouts should say that they timed out and crashes should say they crashed in the TEST-UNEXPECTED-FAIL line; crashes need stacks.

Comment 2

[Michael Henretty [:mikehenrty][:mhenretty]]

Thanks for the info philor. The crashes problem should be fixed permanently by bug 1175116. I'll make that block bug 1174901 as well.

Comment 3

[Aus Lacroix [:aus]]

Going to try and figure out what's going on here.

Comment 4

[Intermittent Failures Robot]

26 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 18
* b2g-inbound: 6
* fx-team: 2

Platform breakdown:
* mulet-linux64: 15
* b2g-linux64: 11

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1236378&startday=2016-01-04&endday=2016-01-04&tree=all

Comment 5

[Aus Lacroix [:aus]]

OK, here's the deal with what's happening.

We receive standard output from different processes effectively and we are placing them into the same aggregate standard output, which is what gets logged.

The issue here is that when we're processing standard output, it won't actually write out everything to the standard output of process A in one go, especially in the case of the screenshot, while other complete lines get written to the standard output of process B.

Processing standard output is done via events currently that are emitted from the child processes and aggregated in a single listening point.

I think that it is reasonable to assume that we should *wait* before outputting standard output from process A until we receive \n in the stream and only output to \n if we don't encounter more but we still have data left to display or the process exits. As an additional, possibly useless, guard we could also timeout after a few seconds and if we have data left to display, display it at that time.

Comment 6

[Intermittent Failures Robot]

18 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 9
* fx-team: 7
* try: 1
* b2g-inbound: 1

Platform breakdown:
* mulet-linux64: 12
* b2g-linux64: 6

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1236378&startday=2016-01-05&endday=2016-01-05&tree=all

Comment 7

[GitHub Autolander Bot]

Attachment: [gaia] nullaus:bug1236378 > mozilla-b2g:master

Comment 8

[Aus Lacroix [:aus]]

Comment on attachment 8704834 [details] [review]
[gaia] nullaus:bug1236378 > mozilla-b2g:master

Looks to be outputting as normal and the try run is green. I'd like to commit this so we can get as much data as possible before the end of the week.

Comment 9

[Gareth Aye [:gaye] (back from PTO)]

Comment on attachment 8704834 [details] [review]
[gaia] nullaus:bug1236378 > mozilla-b2g:master

LGTM with one very small nit. Nice!

Comment 10

[Aus Lacroix [:aus]]

Commit (master): https://github.com/mozilla-b2g/gaia/commit/cf7320010177e7b9489615d27d742e805204f09b

I'm leaving this open until we get more data back to see if we've fixed the specific root problem correctly.

Comment 11

[Aus Lacroix [:aus]]

The root issue where we were breaking the logs and subsequently starring issues to the wrong bugs is now resolved, deployed and verified. \o/!

Comment 12

[Intermittent Failures Robot]

60 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 37
* fx-team: 11
* b2g-inbound: 10
* try: 1
* mozilla-central: 1

Platform breakdown:
* mulet-linux64: 43
* b2g-linux64: 17

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1236378&startday=2016-01-04&endday=2016-01-10&tree=all

Comment 13

[Michael Henretty [:mikehenrty][:mhenretty]]

Removing intermittent keyword so it stops showing up on treeherder.