1050148 - --run-by-dir fails to get proper test summarization for tbpl

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[Joel Maher ( :jmaher ) (UTC -8)]

2 weeks ago we had this working, now it is failing, what appears to be happening is that our summarization here:
http://dxr.mozilla.org/mozilla-central/source/testing/mochitest/runtests.py#1639

seems to be printed before the output from the browser (https://tbpl.mozilla.org/php/getParsedLog.php?id=45382543&tree=Try&full=1):
19:09:08     INFO -  nsTraceRefcnt::DumpStatistics: 1091 entries
19:09:08     INFO -  TEST-PASS | leakcheck | no leaks detected!
19:09:08     INFO -  runtests.py | Running tests: end.
19:09:08     INFO -  0 INFO TEST-START | Shutdown
19:09:08     INFO -  1 INFO Passed:  258288
19:09:08     INFO -  2 INFO Failed:  0
19:09:08     INFO -  3 INFO Todo:    23956
19:09:08     INFO -  4 INFO SimpleTest FINISHED
19:09:08     INFO -  62409 INFO TEST-START | Shutdown
19:09:08     INFO -  62410 INFO Passed:  375
19:09:08     INFO -  62411 INFO Failed:  0
19:09:08     INFO -  62412 INFO Todo:    0
19:09:08     INFO -  62413 INFO Slowest: 1816ms - /tests/dom/imptests/html/html/webappapis/atob/test_base64.html
19:09:08     INFO -  62414 INFO SimpleTest FINISHED
19:09:08     INFO -  62415 INFO TEST-INFO | Ran 1 Loops
19:09:08     INFO -  62416 INFO SimpleTest FINISHED
19:09:08     INFO -  62417 INFO SUITE-END | took 1090s
19:09:08     INFO -  0
19:09:08    ERROR - Return code: 1

^ unrelated this return code 1 might be related to: http://dxr.mozilla.org/mozilla-central/source/testing/mochitest/runtests.py#1706

Is it possible that the structured logging changes have changed the order we output data?

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

:akachkach, you might be able to help us confirm or deny the relationship to structured logging.

Comment 2

[Ahmed Kachkach [:akachkach]]

Since we changed the buffering code, this might be related to structured logging. I have a patch that would pass the summary generation to the Python side, if that makes things easier.

Did this happen before the structured logging patch (= printing the summary generated from the browser side too)? Also, do you have an idea what causes the big difference between the Python-calculated summary and the one from JS?

(code that calculates the summary: http://dxr.mozilla.org/mozilla-central/source/testing/mochitest/runtests.py#1933)

Comment 3

[Joel Maher ( :jmaher ) (UTC -8)]

this worked before (3 weeks ago) and it picked up the summary of tests from the python side.

As for the differences in calculation we are running the entire mochitest harness over and over again and we summarize the results of the entire job instead of the browser instance.

I would be interested in the patch that sends the summary generation to python.

Comment 4

[Ahmed Kachkach [:akachkach]]

Attachment: 0001-Bug-1050148-dump-the-log-buffer-after-each-run-with-.patch

This should do it (the issue was just that the log buffer was only dumped after sending the suite_end message, and not after each iteration of that loop).

Is there a way to try this on tbpl? (I can't run mochitests locally for now)

Comment 5

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8469427 [details] [diff] [review]
0001-Bug-1050148-dump-the-log-buffer-after-each-run-with-.patch

Review of attachment 8469427 [details] [diff] [review]:
-----------------------------------------------------------------

oh, this is cool!  I can test this on try easily, let me add it to my queue.

Comment 6

[Joel Maher ( :jmaher ) (UTC -8)]

this is working on try server, thanks for writing this!

Comment 7

[Ahmed Kachkach [:akachkach]]

Thanks for testing it Joel!

Comment 8

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/2c6e6c9b37a1

Comment 9

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/2c6e6c9b37a1

Comment 10

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/2817d9e1a008