1481435 - Output "thread '...' panicked at" failure messages as log level ERROR not INFO

Status: RESOLVED WORKSFORME

(Release Engineering :: Applications: MozharnessCore, defect)

Description

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

This is treated by Mozharness as failure:

https://dxr.mozilla.org/mozilla-central/rev/4e56a2f51ad739ca52046723448f3129a58f1666/testing/mozharness/mozharness/mozilla/testing/errors.py#129

At the moment, it doesn't get regarded as failure, e.g. at https://treeherder.mozilla.org/logviewer.html#?job_id=190706906&repo=autoland&lineNumber=7509

14:09:11     INFO -  PID 5828 | Executing test 'styleeditor/complicated.js'
14:09:11     INFO -  PID 5828 | [Child 1140, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:09:13     INFO -  PID 5828 | 'complicated.styleeditor.open.settle.DAMP' took 21.77295208707801ms.
14:09:13     INFO -  PID 5828 | Garbage collect
14:09:14     INFO -  PID 5828 | Reload page on 'complicated.styleeditor'
14:09:14     INFO -  PID 5828 | thread '<unnamed>' panicked at 'byte index 340423688 is out of bounds of `localhost:49753`', libcore\str\mod.rs:2094:9
14:09:14     INFO -  PID 5828 | stack backtrace:
14:09:14     INFO -  PID 5828 |    0: 0x654d5d40 - workerlz4_compress
14:09:14     INFO -  PID 5828 |    1: 0x654ce0e9 - workerlz4_compress
14:09:14     INFO -  PID 5828 | [Parent 5828, Gecko_IOThread] WARNING: pipe error: 232: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 513
14:09:14     INFO -  PID 5828 |
14:09:14     INFO -  PID 5828 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x170089,name=PBrowser::Msg_UpdateNativeWindowHandle) Channel error: cannot send/recv
14:09:14     INFO -  PID 5828 |
14:09:14     INFO -  PID 5828 |
14:09:14     INFO -  PID 5828 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x17007C,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
14:09:14     INFO -  PID 5828 |
14:09:14     INFO -  PID 5828 | [Parent 5828, Gecko_IOThread] WARNING: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 188
14:14:11     INFO -  PID 5828 | TEST-UNEXPECTED-FAIL | damp | styleeditor/complicated.js: Test timed out

Treeherder: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=bc1d531d4e251d563f83877eefd454675eb81f2a&selectedJob=190706906

Comment 1

[GitHub Bugzilla PR Linker]

Attachment: Link to GitHub pull-request: https://github.com/mozilla/treeherder/pull/3885

Comment 2

[Ed Morley [:emorley]]

Hi!

It looks like the current mozharness error regex in `testing/mozharness/mozharness/mozilla/testing/errors.py` is broken, since that line is still being output as INFO not error. If that were fixed, Treeherder would pick this line up automatically. (And we're no longer accepting regex changes in Treeherder for cases where the test harness/runner should be using appropriate log line prefixes, so mozharness is where this needs to be fixed.)

ie:

14:09:14     INFO -  PID 5828 | thread '<unnamed>' panicked at 'byte index 340423688 is out of bounds of `localhost:49753`', libcore\str\mod.rs:2094:9

...should be output as:

14:09:14    ERROR -  PID 5828 | thread '<unnamed>' panicked at 'byte index 340423688 is out of bounds of `localhost:49753`', libcore\str\mod.rs:2094:9

Comment 3

[Geoff Brown [:gbrown]]

Should be working now: https://searchfox.org/mozilla-central/rev/0c2945ad4769e2d4428c72e6ddd78d60eb920394/testing/mozharness/mozharness/mozilla/testing/errors.py#137