I can see that Download Statusbar performance testing results on OS X are unrealistically low - around 20ms slowdown both on March 26th and April 2nd. On other platforms the same extension adds 70-80ms to the startup time. The suspicion is that the extension was broken during testing and didn't actually do anything. Yet the log looks perfectly normal. To help investigate such cases (and also the cases where an extension is abnormally slow on some platform) Talos needs to capture error console output in addition to dump() calls.

Talos captures all console output - the basic command for running the browser is something like 'firefox.exe > log.txt'. We are already capturing everything that there is to see.

Reopening - I was talking about Error Console (formerly JavaScript Console). In other words, JavaScript errors and various browser warnings need to be captured, this would in particular help verify that the test is valid.

Asked around, and this is how mozmill handles the problem: https://github.com/ahal/mozmill/blob/consoleReporting/mozmill/mozmill/extension/resource/modules/frame.js#L449

Yes, registering an nsIConsoleListener instance and calling dump() for all the messages reported should be the way to go. Unfortunately, this won't be possible without having some minimal extension installed to do the job.

Obviously, installing an extension to capture the errors isn't the ideal course of action - this extension itself might skew the results. Then again, only the messages during startup are interesting. So getting the list of messages from the console service in startup_test.html and tspaint_test.html should be sufficient.

I'll get this into talos staging and see how it goes.

I believe that the placement of the extra dump lines will affect our reported ts_shutdown numbers, as the the browser will have to complete the dump before it can continue shutting down. We'll want to dump this info before we collect our pre-shutdown timestamp and close the browser.

New patch, this time without skewing ts_shutdown results. Making window closing asynchronous isn't strictly necessary but I noticed that closing the browser synchronously in the load event skews the results considerably - for a synchronous close I see 200ms for ts_shutdown, with an asynchronous close I get only 175ms. I guess that this is because the browser isn't quite finished starting up when the load event fires so ts_shutdown right now ends up measuring some of the delayed startup overhead. I had to get rid of document.write() - in the load event it will replace the current document which will clear the window's scope and break code executing asynchronously. Changing document.body.textContent will show the text without causing further reaching effects.

Will be testing new patch on staging this week.

The patch is green on all platforms. I'm confident that it will not break the ts/tpaint tests. It should be rolled out in an appropriate downtime as there could be number wobble.

Comment on attachment 527230 [details] [diff] [review] [checked in]Patch v2 changeset: 233:025a27bd2cd8

Deployed.