Closed Bug 761257 Opened 9 years ago Closed 9 years ago
Further improve Web Console output performance
In bug 722685 we've done work to improve the Web Console output performance, but due to time constraints we only implemented queuing of message output. Messages are still created all at once. This can still cause problems with a lot of calls to the console API. We should also use https://developer.mozilla.org/en/Performance/Reporting_a_Performance_Problem ... to investigate how our code executes, which are the hot spots. We should also finetune the queuing behavior, because at this point it is a simple implementation that outputs N messages, every M milliseconds until the queue is empty.
Assignee: nobody → mihai.sucan
Status: NEW → ASSIGNED
Proposed patch. This should complete our work on Web Console output performance. Changes: - make a single call to the timer that outputs messages to process DEFAULT_LOG_LIMIT (200), so we do not spend time scrolling too often. This is based on a suggestion from Boris (if well understood!). This has better perceived performance - UI is more responsive when you update more messages at once and you do less reflows as a consequence. - different output throttle strategy based on how slow we update the UI: decided to try to update output every one second - irrespective of how many messages are added to the queue or how many are displayed the given timer interval. - went down to 50ms for the timer resolution, to check more often what needs to be done. In normal use updates happen in 50ms. When there's "heavy fire" we throttle to 1000ms (as explained above). - rewire the message creation and output mechanisms in the the entire Web Console to queue not just output but message creation - unlike the previous performance patch. This allows the code to prevent freezing the browser while, say, 50000 messages are created. - added code to ConsoleAPI.js to split processing the console API calls into chunks in the timer that was added in the previous performance patch. I did this again to avoid browser freezing for a long time while waiting for N calls to be processed. The results: I ran 50000 calls to console.log("foo " +i ), with the Web Console open. Firefox 13: Time to display all messages: ~306 s Time to return from page script loop: ~306 s Note: 5 minutes ... browser is frozen all of the time, entirely unusable. Firefox 15: Display: ~30 s Return: ~2600 ms Note: browser stalls and updates and stalls, as it processes the calls. This only lasts for about ~33 seconds. Firefox 16 (with this patch): Display: ~14 s Return: ~2600 ms Note: browser stalls for ~2600 ms until the return from loop happens, then the browser is usable for the duration of visual updates, but you can feel work is happening - you feel it's slowish. This is an improvement that avoid the browser being killed for being unresponsive. Chromium 18: Display: after 600 s I closed the browser. Return: ~3000 ms Note: page is frozen until return from loop happens, then Web Inspector freezes after a few thousands of messages and I couldn't get it unfreeze. Opera 12: Display: after 600 s I closed the browser. Return: ~1100 ms Note: browser stalls for about one second then Dragonfly starts updating the output and freezing its window. Browser is sluggish until Dragonfly completes - which it didn't for me. I should note that at this point we should do well enough for games that log a lot of data at once. If the Web Console still feels slow, I'd like to see a test case that shows typical work load when working on a game in Firefox. There are a number of test changes because the Web Console still has some tests that expected specific timings for certain kinds of output messages. Boris: I am asking you for feedback, since you've been very helpful with suggestions. Any comments on how to improve this code are much appreciated. Thank you! Looking forward to comments!
This patch depends on the patch from bug 761157. Try push: https://tbpl.mozilla.org/?tree=Try&rev=ad2b6e81c01f
Depends on: 761157
Comment on attachment 631117 [details] [diff] [review] proposed patch Those changes sound great (and the numbers bear it out). I don't think I have anything to add!
Attachment #631117 - Flags: feedback?(bzbarsky) → feedback+
Rebased the patch so it applies cleanly on top of the dependent patch. Boris: thank you very much for your time to look into the patch and to provide us with suggestions on how to improve the Web Console output performance.
Comment on attachment 631975 [details] [diff] [review] rebased patch Looks good! If you want to rename your nsITimer variable to gTimer in this patch, I won't complain.
Attachment #631975 - Flags: review?(dcamp) → review+
Thank you for the r+! Try push results: https://tbpl.mozilla.org/?tree=Try&rev=665e11e32550
Attachment #631975 - Attachment is obsolete: true
Comment on attachment 632823 [details] [diff] [review] [in-fx-team] review comment addressed https://hg.mozilla.org/integration/fx-team/rev/dff9bab548bf
Attachment #632823 - Attachment description: review comment addressed → [in-fx-team] review comment addressed
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 16
You need to log in before you can comment on or make changes to this bug.