674750 - XPCShell test should show time taken to run tests

Status: RESOLVED FIXED

(Testing :: XPCShell Harness, defect)

Description

[William Lachance (:wlach)]

Attachment: Patch to add timing information to tests passing in xpcshell

Here's a quick and dirty patch to add some timing information to the XPCShell test log. I used this, along with some small tools I wrote up in python, to figure out which XPCShell tests really run a lot slower on win32 (for bug 617503).

Comment 1

[cmtalbert]

Comment on attachment 548947 [details] [diff] [review]
Patch to add timing information to tests passing in xpcshell

Ideally we'd do this like mochitest where you have a TEST-END message, i.e:
846 INFO TEST-PASS | /tests/toolkit/components/passwordmgr/test/test_basic_form_0pw.html | Checking for unfilled text field (form 4) - "" should equal ""
847 INFO TEST-PASS | /tests/toolkit/components/passwordmgr/test/test_basic_form_0pw.html | Checking for unfilled text field (form 5) - "" should equal ""
848 INFO TEST-END | /tests/toolkit/components/passwordmgr/test/test_basic_form_0pw.html | finished in 489ms

But with xpcshell, such a message would be duplicitous since the print line here is essentially "Test-END" and if you change it from "TEST-PASS" it will break the log parsers.  So, let's go with this as it's light weight and simple. But one day, I still dream of making one log format across all the harnesses, but it's a bit out of scope of this bug.

My one nit I'd like to see addressed before landing is that the units ought to be in milliseconds since that's what the other harnesses measure their time in, not seconds.  And I'd use a floating point notation rather than %s so you can control the number of digits to the right of the decimal that are printed in order to make a nice display.  So, r+ with those ^ changes.

Comment 2

[cmtalbert]

Jgriffin, can you help wlach land this, and also please verify that this won't hurt the log parsers.  (I think it should be fine, but you may want to request modifications to the woo parser so we can pull out this timing info as part of this bug).

Comment 3

[Jonathan Griffin (:jgriffin)]

I've verified this change doesn't interfere with the logparser.

Comment 4

[William Lachance (:wlach)]

Attachment: Revised patch to add timing information to tests passing in xpcshell

Addressing Clint's feedback

Comment 5

[Jonathan Griffin (:jgriffin)]

Pushed as http://hg.mozilla.org/mozilla-central/rev/e44dad2d2745