Talos should capture error console output in the logs



8 years ago
8 years ago


(Reporter: gaubugzilla, Assigned: gaubugzilla)


Firefox Tracking Flags

(Not tracked)



(1 attachment, 1 obsolete attachment)



8 years ago
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.
Blocks: 648784
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.
Last Resolved: 8 years ago
Resolution: --- → INVALID

Comment 2

8 years ago
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.
Resolution: INVALID → ---

Comment 4

8 years ago
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.

Comment 5

8 years ago
Created attachment 526852 [details] [diff] [review]
Proposed patch

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.
Assignee: nobody → trev.moz
Attachment #526852 - Flags: review?(anodelman)
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.

Comment 8

8 years ago
Created attachment 527230 [details] [diff] [review]
[checked in]Patch v2

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.
Attachment #526852 - Attachment is obsolete: true
Attachment #526852 - Flags: review?(anodelman)
Attachment #527230 - Flags: review?(anodelman)
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.
Attachment #527230 - Flags: review?(anodelman) → review+
Comment on attachment 527230 [details] [diff] [review]
[checked in]Patch v2

changeset:   233:025a27bd2cd8
Attachment #527230 - Attachment description: Patch v2 → [checked in]Patch v2
Last Resolved: 8 years ago8 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.