1591678 - task with message 'TEST-UNEXPECTED-FAIL | leakcheck | tab missing output line for total leaks!' set as successful

Status: REOPENED

(Testing :: Mozbase, defect, P2)

Description

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

https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&selectedJob=273066105&resultStatus=superseded%2Cusercancel%2Cretry%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&revision=adfac78ca4eb2fa1b9783f5fce561a8b6532d4d7

has

TEST-UNEXPECTED-FAIL | leakcheck | tab missing output line for total leaks!

but is set as TBPL SUCCESS: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=273066105&repo=autoland&lineNumber=44590

errors.py assumes there is nothing between | and missing output line for total leaks!

Comment 1

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

Attachment: Bug 1591678 - add process name to regexps for harness errors to let their occurrences trigger the task to fail. r?jlund

Comment 2

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ae350e8881e5
add process name to regexps for harness errors to let their occurrences trigger the task to fail. r=jlund

Comment 3

[Bogdan Tara[:bogdan_tara | bogdant]]

https://hg.mozilla.org/mozilla-central/rev/ae350e8881e5

Comment 4

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

This didn't fix it: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&selectedJob=274356961&resultStatus=superseded%2Cusercancel%2Cretry%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&revision=2b857b37df75125d7f12b46bfe6c28eac38593a3

Comment 5

[Andrew McCreight [:mccr8]]

Can somebody please look at fixing this? This failure is still not turning jobs orange. Thanks.

The green jobs here are an example of this: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&searchStr=linux%2C18.04%2Cx64%2Cdebug%2Cmochitests%2Ctest-linux1804-64%2Fdebug-mochitest-plain-e10s-&revision=821bbb36f7d37f1e2dd73d193e728712a55c143d&selectedTaskRun=F02_m2pHQ0yH2GZhGiad-g.0

Fortunately a sheriff noticed that this was happening so we were able to back out my patch that caused it, but it would be better to not have to rely on that. It would also be harder to notice if the failure to create a log was only happening in some test directories instead of in all of them.

Comment 6

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

See the 'Failure Summary' tab for this task as example.

For missing output line for total leaks!, self.leaked gets set to false (src. In other words, nothing tracks it as an error and the logic to set the task as failure will keep the default TBPL_SUCCESS.

Shall in this case self.num_errors be set and self.tbpl_status be set based on that?

Comment 7

[Geoff Brown [:gbrown]]

I don't recall ever being involved in mozharness leak reporting -- I may not know what I'm talking about.

I note the harness_error_re is defined by https://searchfox.org/mozilla-central/rev/7ec7ee4a9bde171ba195ab46ed6077e4baaef34d/testing/mozharness/mozharness/mozilla/testing/errors.py#102. Reading through https://searchfox.org/mozilla-central/rev/7ec7ee4a9bde171ba195ab46ed6077e4baaef34d/testing/mozharness/mozharness/mozilla/testing/unittest.py#159-168, I think the intent has been:

    if "negative leaks caught!" or "\d+ bytes leaked" is found on a "TEST-UNEXPECTED-FAIL" line:
         self.leaked = True
   elif "missing output line for total leaks!" is found on a "TEST-UNEXPECTED-FAIL" line:
         self.leaked = None
   else:
         self.leaked = False

With https://bugzilla.mozilla.org/show_bug.cgi?id=1591678#c3, "<something> missing output line for total leaks!" is now treated the same as "missing output line for total leaks!" was originally - that seems right.

I don't see any existing code that links self.leaked to success/failure of the mozharness run.

I don't think self.num_errors should be modified for leaks.

If we want to fail, I think this is sufficient:
self.tbpl_status = self.worst_level(TBPL_FAILURE, self.tbpl_status, levels=TBPL_WORST_LEVEL_TUPLE)
but I note that we do not currently do that for other leak conditions, nor for crashes (which seems odd/wrong).

Comment 8

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

Andrew, can you provide insight into the reasoning for the current behavior of the leak reporting and guide how it shall be done?

Comment 9

[Andrew Halberstadt [:ahal]]

It's also been a long time since I've looked at mozharness log parsing and status setting, but those regexes should only be used for unstructured output. The mochitest harness uses mozlog actions to handle leak messages:
https://searchfox.org/mozilla-central/source/testing/mozharness/mozharness/mozilla/structuredlog.py#22

I believe this is a bug in mozlog's StatusHandler here:
https://searchfox.org/mozilla-central/source/testing/mozbase/mozlog/mozlog/handlers/statushandler.py#79

Basically we default the bytes value to 0, though according to the other formatters, a None value means the total line is missing. I'll put up a patch shortly, though may be a little bit before I can test it. I'll leave the needinfo to remind myself.

Comment 10

[Andrew Halberstadt [:ahal]]

Attachment: Bug 1591678 - [mozlog] Ensure missing leak totals count as a failure in the StatusHandler, r?gbrown

Comment 11

[Andrew Halberstadt [:ahal]]

I rebased my fix on the patch linked in comment 5 and it seems to work well:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=a7ada14f594eeaf7b47edda0082602a68adeb97b

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b932e78a6bbc
[mozlog] Ensure missing leak totals count as a failure in the StatusHandler, r=gbrown

Comment 13

[Andrew McCreight [:mccr8]]

Thank you for fixing this!

Comment 14

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/b932e78a6bbc

Comment 15

[Razvan Maries]

Backed out https://hg.mozilla.org/integration/autoland/rev/b932e78a6bbc as requested here: https://bugzilla.mozilla.org/show_bug.cgi?id=1651716#c10.
Backout: https://hg.mozilla.org/integration/autoland/rev/c0c596cabd448fe62cd613b249668b6d721b72a7

Comment 16

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

Backout merged: https://hg.mozilla.org/mozilla-central/rev/c0c596cabd44

Comment 17

[Intermittent Failures Robot]

1 failures in 3712 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1591678&startday=2020-11-30&endday=2020-12-06&tree=all

Comment 18

[Geoff Brown [:gbrown]]

Any interest in the remaining unlanded patch?

Comment 19

[Andrew Halberstadt [:ahal]]

Yeah, I think it's still something we'd want. Though if I'm remembering properly fixing the thing that caused the backout was going to be tricky. There should be more context in bug 1651716 (I see there have been many comments since the backout that I haven't been following though).