Boris Zbarsky [:bzbarsky] Reporter
	Description • 8 years ago

Today I pushed a patch (part 2 of bug 504622) that removed some assertions from the tree.  We had a test (layout/forms/crashtests/378413-1.xhtml) that was annotated like so:

  asserts(4-10) load 378413-1.xhtml # bug 424225, bug 402850?

because it triggered those assertions.  Removing them should have caused every single debug crashtest run, including the one in the try runs I had done, to go orange, since the test no longer asserted.

However, the _only_ crashtest run that went orange was the "Android 4.3 API15+ debug" tc-R(6) run, with an UNEXPECTED-PASS.  You can see the push results at https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=c024721d9b03fac54eee5730a34f8e7bfbff2129

I have double-checked that on the previous push (<https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=d254eb61360d3c20172eb7aba1154e2779850263&selectedJob=40057296>) the assertions are in fact triggering on the various debug crashtest runs involved.  I have also double-checked that they are not in fact happening with my patch (which is good, because I removed them!).  What I don't understand is why all those runs did not go orange.  Something is seriously broken here.

Wes, do you have any idea whom I should really be ccing on this bug?

	David Baron :dbaron:
	Comment 1 • 8 years ago

Could this be fallout from structured logging?

	James Graham [:jgraham] Assignee
	Comment 2 • 8 years ago

So in the linux64-debug logs I see:

[task 2016-11-29T21:37:31.981439Z] 21:37:31     INFO - REFTEST TEST-UNEXPECTED-PASS | file:///home/worker/workspace/build/tests/reftest/tests/layout/forms/crashtests/378413-1.xhtml | assertion count 0 is less than expected 4 to 10 assertions

So the problem is that in the structured logs this is being logged as random process output, and mozharness doesn't look at that when determining the job status. I think the right way to fix this is to change the reftest harness to log this in some way that mozharness will pay attention to. I will look at fixing that.

	James Graham [:jgraham] Assignee
	Comment 3 • 8 years ago

This is more accurately fallout from 1261199 which started using the structured logs only for determining job status in mozharness and hence treeherder.

	James Graham [:jgraham] Assignee
	Comment 4 • 8 years ago

https://treeherder.mozilla.org/#/jobs?repo=try&revision=795ea47cdef339d58bba5b9b3d51515052426f0b&selectedJob=32095865

	James Graham [:jgraham] Assignee
	Comment 5 • 8 years ago

Also https://treeherder.mozilla.org/#/jobs?repo=try&revision=391597c1549ee4208a38fd75d9a056d0aba3fd9a&selectedJob=32161553

I can get the patch reviewed, but I'm not sure what to do about these oranges that have crept in in the meantime.

	Andrew Halberstadt [:ahal]
	Comment 7 • 8 years ago

(In reply to James Graham [:jgraham] from comment #5)
> Also
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=391597c1549ee4208a38fd75d9a056d0aba3fd9a&selectedJob=3
> 2161553
> 
> I can get the patch reviewed, but I'm not sure what to do about these
> oranges that have crept in in the meantime.

We need to get this landed asap, so probably file a bug and add an expected assertion to the failing tests. I'll volunteer.

	Andrew Halberstadt [:ahal]
	Comment 8 • 8 years ago
mozreview-review

Comment on attachment 8816103 [details]
Bug 1321127 - Add a assertion_count action to mozlog,

https://reviewboard.mozilla.org/r/96898/#review97124

Thanks for jumping on this. This looks good, we should also get mochitest et al to use this as well.

::: testing/mozbase/mozlog/mozlog/formatters/machformatter.py:283
(Diff revision 1)
>                                                             data["expected"],
>                                                             message))
>          return rv
>  
> +    def assertion_count(self, data):
> +        term = self.terminal if self.terminal is not None else NullTerminal()

This is out of scope for this bug, but I wrote a handy drop-in replacement NullTerminal for blessings.Terminal here:
https://dxr.mozilla.org/mozilla-central/source/python/mozlint/mozlint/formatters/stylish.py#15

It can handle everything a regular Terminal can.

::: testing/mozbase/mozlog/mozlog/formatters/machformatter.py:304
(Diff revision 1)
> +                (color(status if status == expected else ("%s expected %s" %
> +                                                          (status, expected))),

In the event of expected fail, I think this should print EXPECTED-FAIL in the first substitution. Just printing FAIL will look like something went wrong and might even be flagged by treeherder.

	James Graham [:jgraham] Assignee
	Comment 9 • 8 years ago
mozreview-review-reply

Comment on attachment 8816103 [details]
Bug 1321127 - Add a assertion_count action to mozlog,

https://reviewboard.mozilla.org/r/96898/#review97124

> In the event of expected fail, I think this should print EXPECTED-FAIL in the first substitution. Just printing FAIL will look like something went wrong and might even be flagged by treeherder.

Treeherder never gets mach formatter input, only tbpl formatter input, so that isn't a concern.

I agree that this looks too much like the tbplformatter style though and it should probably not print anything if the asssertions are in the expected range and something like Assertion count: expected 1-3, got 4" if it fails

	David Baron :dbaron:
	Comment 12 • 8 years ago
mozreview-review

Comment on attachment 8816154 [details]
Bug 1321127 - Add temporary annotations for asserts missed by CI,

https://reviewboard.mozilla.org/r/96932/#review97188

::: layout/generic/crashtests/crashtests.list:15
(Diff revision 1)
>  load 264937-1.html
>  load 265867-1.html
>  load 265867-2.html
>  load 286491.html
>  load 289864-1.html
> -load 295292-1.html
> +asserts(1) load 295292-1.html

I'm a little confused as to why this is all-platforms if the assertion detection wasn't broken on Android.  Does this need to be platform-specific?

(Also, please file a bug on it and note the bug number in a comment at the end of the line.)

::: layout/generic/crashtests/crashtests.list:632
(Diff revision 1)
>  load text-overflow-bug713610.html
>  load text-overflow-form-elements.html
>  load text-overflow-iframe.html
>  asserts-if(Android,2-4) asserts-if(!Android,4) load 1225005.html # bug 682647 and bug 448083
>  load 1233191.html
> -skip-if(Android) load 1271765.html
> +skip-if(Android) asserts(3) load 1271765.html

It's not clear why the skip-if(Android) was added -- it was between bug 1271765 comment 124 and bug 1271765 comment 146 -- in the diff in bug 1271765 comment 133 -- but I bet you can remove it.

Also, again, please file bug and comment here.

	Andrew Halberstadt [:ahal]
	Comment 16 • 8 years ago
mozreview-review

Comment on attachment 8816103 [details]
Bug 1321127 - Add a assertion_count action to mozlog,

https://reviewboard.mozilla.org/r/96898/#review98022

I re-reviewed the 1-3 interdiff, and lgtm.

	Pulsebot
	Comment 17 • 8 years ago

Pushed by james@hoppipolla.co.uk:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2be3e937ecd9
Add a assertion_count action to mozlog, r=ahal
https://hg.mozilla.org/integration/mozilla-inbound/rev/48ce71d365d8
Add temporary annotations for asserts missed by CI, r=dbaron

	Carsten Book [:Tomcat]
	Comment 18 • 8 years ago
bugherder

https://hg.mozilla.org/mozilla-central/rev/2be3e937ecd9
https://hg.mozilla.org/mozilla-central/rev/48ce71d365d8