Bug 1326162 - new recipe page takes a long time to render for very large recipes, may trigger Unresponsive Script warning
Summary: new recipe page takes a long time to render for very large recipes, may trigg...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Beaker
Classification: Retired
Component: web UI
Version: develop
Hardware: Unspecified
OS: Unspecified
medium
medium vote
Target Milestone: 23.0
Assignee: matt jia
QA Contact: tools-bugs
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-04-12 02:29 UTC by wangdong
Modified: 2016-07-07 23:12 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-07-07 23:12:43 UTC


Attachments (Terms of Use)
Warning message. (113.36 KB, image/png)
2016-04-12 02:29 UTC, wangdong
no flags Details

Description wangdong 2016-04-12 02:29:42 UTC
Created attachment 1146176 [details]
Warning message.

Description of problem:


Version-Release number of selected component (if applicable):
23.0.git.148.a48f135

How reproducible:


Steps to Reproduce:
1. Create a job with large recipes.

    <task name="/distribution/command" role="STANDALONE">
        <params>
          <param name="CMDS_TO_RUN" value="for i in {1..8000} ; do rhts-report-result dummy-result-$i PASS /dev/null ; done"/>
        </params>
    </task>
2. Run this job and wait it complete
3. Switch to job recipe page.

Actual results:
Warning message will show. Please refer to attachment.

Expected results:
No warning message.

Additional info:

Comment 1 Dan Callaghan 2016-04-19 06:30:27 UTC
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.

Comment 2 matt jia 2016-04-21 01:54:39 UTC
(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/

Comment 3 Dan Callaghan 2016-04-26 06:47:22 UTC
Matt, can you please make a note of your before and after timing numbers here (ideally in Firefox, or both Firefox and Chrome).

Comment 4 Dan Callaghan 2016-04-26 06:52:12 UTC
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).

Comment 5 matt jia 2016-04-27 06:55:44 UTC
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'.

Comment 6 matt jia 2016-04-27 23:43:43 UTC
(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.

Comment 7 matt jia 2016-04-28 04:32:53 UTC
With this patch https://gerrit.beaker-project.org/#/c/4843/, the response data now has been reduced to 1.9MB.

Comment 8 matt jia 2016-05-09 00:55:59 UTC
(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/

Comment 9 matt jia 2016-05-09 00:59:40 UTC
(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.

Comment 10 Dan Callaghan 2016-05-10 02:00:02 UTC
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.

Comment 11 Dan Callaghan 2016-05-10 02:05:55 UTC
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.

Comment 12 Dan Callaghan 2016-05-10 02:32:31 UTC
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

Comment 13 Dan Callaghan 2016-05-10 03:13:17 UTC
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

Comment 14 Dan Callaghan 2016-05-10 03:23:20 UTC
The remaining profile seems to be dominated by $.html() and various moment.js stuff that happens inside RecipeTaskResultView.render...

Comment 15 Dan Callaghan 2016-05-10 05:35:06 UTC
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.

Comment 16 Dan Callaghan 2016-05-10 07:03:45 UTC
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.

Comment 17 Dan Callaghan 2016-05-10 07:45:31 UTC
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.

Comment 20 Dan Callaghan 2016-07-07 23:12:43 UTC
Beaker 23.0 has been released.


Note You need to log in before you can comment on or make changes to this bug.