Bug 1326162

While fixing this we should ensure we also trim down the returned JSON as much as possible -- now (before 23.0 is released) is our last opportunity to do that, once it's released we can't remove anything as it would break API.

For example installation.rendered_kickstart.kickstart is one unnecessary piece which I already put up a patch for removing.

(In reply to Dan Callaghan from comment #1)
> While fixing this we should ensure we also trim down the returned JSON as
> much as possible -- now (before 23.0 is released) is our last opportunity to
> do that, once it's released we can't remove anything as it would break API.
> 
> For example installation.rendered_kickstart.kickstart is one unnecessary
> piece which I already put up a patch for removing.

Remove the recipe tasks from job and recipe set JSON:

    https://gerrit.beaker-project.org/#/c/4823/

And trim down the beaker tasks in recipe JSON:

    https://gerrit.beaker-project.org/#/c/4821/

Matt, can you please make a note of your before and after timing numbers here (ideally in Firefox, or both Firefox and Chrome).

So there's actually two sides to this which we want to address: the server-side response time and response size (which should be decreased by the above patches in comment 2, and which we should decrease further if possible) and more importantly the CPU time spend rendering the page on the client side (which is what causes the Unresponsive Script warning).

I have one patch to avoid causing multiple DOM reflows when rendering large results.


https://gerrit.beaker-project.org/#/c/4838/


I am using a recipe with results 7500 as an example:

On Chrome with the google Timeline:

Before:

   the response data: 9MB
   the response time: 17.5s
   the total loading page time: 32s(11s on scripting and 6s on rendering)

Cannot even work on the firefox as it is too slow.

After merging the above patches, the numbers are:

After:
   the response data: 2.3MB
   the response time: 15s
   the total loading page time: 28s(9.4s on scripting and 6s on rendering)

On Firefox, it takes 31s to load the page and triggers 'Unresponsive Script warning'.

(In reply to matt jia from comment #5)
> 
> After:
>    the response data: 2.3MB
>    the response time: 15s
>    the total loading page time: 28s(9.4s on scripting and 6s on rendering)
> 
> On Firefox, it takes 31s to load the page and triggers 'Unresponsive Script
> warning'.

It is still not perfect yet, but right now the above patches make this case workable on the Firefox with one click to 'Continue' when the 'Warning Unresponsive script' dialog appears.

With this patch https://gerrit.beaker-project.org/#/c/4843/, the response data now has been reduced to 1.9MB.

(In reply to matt jia from comment #7)
> With this patch https://gerrit.beaker-project.org/#/c/4843/, the response
> data now has been reduced to 1.9MB.

It turns that this is a wrong approach. We achieve the same result with this patch instead.

   https://gerrit.beaker-project.org/#/c/4850/

(In reply to matt jia from comment #5)
> I have one patch to avoid causing multiple DOM reflows when rendering large
> results.
> 
> 
> https://gerrit.beaker-project.org/#/c/4838/
> 

This patch has been updated to fix the script warning on Firefox. I have tested it on my testing environment and it seems working.

I have a patch to turn off local-datetime.js on the newer pages (including recipe page) but it actually seems to make things slightly slower. It seems like the local-datetime.js stuff was not actually a significant contributor, at least in Chrome.

https://gerrit.beaker-project.org/4872

Timing of DOMContentLoadedEvent before:

23.62 s
0.31 ms Scripting (Self)
21.59 s Scripting (Children)
1.07 s Loading
961.83 ms Rendering

and after:

24.35 s
0.32 ms Scripting (Self)
22.34 s Scripting (Children)
1.06 s Loading
946.84 ms Rendering

Tested using R:1227025 from a production dump.

Scratch that. The after timing was not using the patched local-datetime.js. Correct timing is:

(In reply to Dan Callaghan from comment #10)
> Timing of DOMContentLoadedEvent before:
> 
> 23.62 s
> 0.31 ms Scripting (Self)
> 21.59 s Scripting (Children)
> 1.07 s Loading
> 961.83 ms Rendering
> 
> and after:

22.66 s
0.46 ms Scripting (Self)
20.66 s Scripting (Children)
1.06 s Loading
944.39 ms Rendering

so the patch makes a slight improvement.

This patch, extracted from Matt's patch above, to insert all the tasks and results into the DOM in a single operation:

http://gerrit.beaker-project.org/4875

doesn't make any substantial difference:

23.02 s
0.37 ms Scripting (Self)
21.01 s Scripting (Children)
1.05 s Loading
955.35 ms Rendering

The profile shows that we are spending a large amount of time just doing the $.html() call in each of the views, where we take the template output and feed it back into a DOM element to be parsed. This patch converts those two views to use DOM manipulation, which basically eliminates those views' rendering time from the profile (at the cost of uglier code in the view -- but they are both simple views so it's not too bad).

http://gerrit.beaker-project.org/4876

15.92 s
0.34 ms Scripting (Self)
14.21 s Scripting (Children)
556.14 ms Loading
1.15 s Rendering

The remaining profile seems to be dominated by $.html() and various moment.js stuff that happens inside RecipeTaskResultView.render...

So I mentioned this on Gerrit but I will comment here for posterity... My issue with the patch in comment 9 is that it doesn't actually speed anything up, it just uses setTimeout trickery to occasionally yield to the browser so that the unresponsive script warning is avoided. The script will still take 30 seconds or whatever to render the page though.

I would rather we find ways to actually optimise the results rendering so that it becomes usable for large recipes. If we can get a pathologically large recipe from 30 seconds to 5 seconds, it also means we are improving the rendering time for a normal-sized recipe by roughly the same factor (6 seconds down to 1 second, for instance) so it's not just effort wasted on a corner case.

This patch removes (most of) the moment stuff from the DOMContentLoaded profile, at the cost of slightly increased time spent parsing the model JSON. It's really just moving the work from rendering into model parsing -- but also eliminating a lot of the duplicate re-parsing which we were doing in the templates.

http://gerrit.beaker-project.org/4878

DOMContentLoaded is now:

13.03 s
0.34 ms Scripting (Self)
11.35 s Scripting (Children)
534.75 ms Loading
1.14 s Rendering

whereas the profile for Recipe.parse is now:

1.41 s
0.63 ms Scripting (Self)
1.41 s Scripting (Children)

which is a moderate increase over the previous:

608.16 ms
1.40 ms Scripting (Self)
606.76 ms Scripting (Children)

We could probably further reduce the moment parsing CPU time if we made the server send the timestamps in strict ISO8601 format, so that moment can use the native browser ISO8601 Date parsing... but I'm not sure if that's worth the gain.

The next option would be to avoid using bootstrap-popover.js or to convert the recipe-task-result JST template into raw DOM calls, but that is starting to get messy and I don't think it is really worthwhile. With the patches above I can load R:1227025 in Firefox without any "unresponsive script" warnings so that might already be good enough.

Beaker 23.0 has been released.