1515123 - devtools network response from a Lightning REPORT request loads very slowly (long delay) with UI freeze/not responding

Status: RESOLVED WORKSFORME

(Calendar :: General, defect)

Description

[Richard Leger]

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:64.0) Gecko/20100101 Firefox/64.0

Steps to reproduce:

1. Starup Thunderbird 64.0b3 (32-bit) on Windows 10 Pro 64bits 1803 (Version 10.0.17134.407), no email setup, one network (caldav) calendar (with ~4000 items) setup only, Find Events > All Events > No order by any columns (default).
2. Open devtools (Ctrl+Shift+I) > Network
3. Open one of the multiple REPORT request send/receive by Lightning add-on
4. Select Response tab to see the response 


Actual results:

devtools is very slow to load the response with mention (Not Responding) appearing, if you wait for long while, it does show the response as raw text then freeze again... and then after another long while... it finally show colored formatted response. But slughish to scroll up and down... the response UI...

Switching to another REPORT request listed, would repeat the process and same issue.


Expected results:

Response content shall appears immediately without freeze/not responding.
Switching to another REPORT request shall show response content immediately for that request.

Comment 1

[Richard Leger]

For the same calendar and with the same setup with Thunderbird 64.0b4 (64 bits) on Mac OS X 10.13.6, the response seems to load fine and immediately at all time.

Comment 2

[Richard Leger]

Related to Bug 1473163 ?

Comment 3

[Jorg K (CEST = GMT+2)]

Can you file Calendar bugs in Calendar please. Are you saying that it's fixed in TB 64 b4?

Comment 4

[Philipp Kewisch [:Fallen] [:📆][:🧩]]

I'm not sure if this is a devtools bug or not, but I am not sure what Lightning could be doing to slow this down. This will be difficult to reproduce, but is there any chance you can trigger a request like this in Firefox and see if the response is slow to load there?

Comment 5

[Richard Leger]

(In reply to Jorg K (GMT+1) from comment #3)
> Can you file Calendar bugs in Calendar please. 

I would not think it is a Lightning issue... but it may be linked to the loading of calendar items.

> Are you saying that it's fixed in TB 64 b4?

I am not saying it is fixed in TB 64 b4, I am just reporting observations.
To confirm it would be fixed, I would need to have b4 installed on my Windows machine and redo the exact same test. Currently this version is not yet available via the beta channel to me.

Comment 6

[Richard Leger]

(In reply to Philipp Kewisch [:Fallen] [:📆] from comment #4)
> I'm not sure if this is a devtools bug or not, but I am not sure what
> Lightning could be doing to slow this down. This will be difficult to
> reproduce, but is there any chance you can trigger a request like this in
> Firefox and see if the response is slow to load there?

I don't see how I can trigger such requests (Lightening multi-get request toward my calendar appearing as REPORT requests in devtools network) in Firefox. Any suggestions welcome.

For the time being, what I have done which may be the closest to reproduce the issue in Firefox 64.0 (64-bit), is to go to something like https://example.domain.com/davical/caldav.php/richard/home to download my full .ics calendar. The network request is about 1.7Mb in size and when I open the request and click response tab... it take ages to load the response... with intermittent freeze/UI not responding... and script unresponsive alert appearing couple of time (see attached in my next comment).

Comment 7

[Richard Leger]

Attachment: warning.unresponsive.script.when.loading.reasponse.png

When loading response, the attached alert keeps appearing a couple of time after each freeze/UI not responding... pressing Continue keep the process going and Firefox freeze/UI not responding... then repeat couple of time, until the response appear complete and process complete. After the first alert some response content do appear in the UI response area...

Comment 8

[Richard Leger]

Could it be linked to big size response or the type of response (calendar events) causing parsing issue when loading data into Firefox devtools network response UI area? My understanding is that they are two steps in the response content loading. One is to get the raw data response, and another one to somehow format it on screen (color syntaxing) but with events data no color syntaxing appears. The slowness seems to appear in both cases...

Comment 9

[Richard Leger]

I also observed additional slowness with the devtools in general more in Bug 1513551.

Comment 10

[Richard Leger]

Still happening in TB Version 65.0b1 (32-bit) but to less extend in the sense that error message is not longer appearing... but not responding issue and delay remain... so it does not seems to crash the debugger or prevent access to TB as interface remain intermittently accessible as there seems to have been some improvement with the "multiprocessing" of TB or the processing sharing between different part of TB.

Though I believe the underlying issue and root cause remain.

Comment 11

[Richard Leger]

(In reply to Richard Leger from comment #10)

Still happening in TB Version 65.0b1 (32-bit) but to less extend in the
sense that error message is not longer appearing... but not responding issue
and delay remain... so it does not seems to crash the debugger or prevent
access to TB as interface remain intermittently accessible as there seems to
have been some improvement with the "multiprocessing" of TB or the
processing sharing between different part of TB.

Though I believe the underlying issue and root cause remain.

Same as previously in TB Version 66.0b1 (32-bit), click on Dev Tool > Network > REPORT > Response

A 1.16MB xml response take about 70seconds to appear, and another 130seconds to be coloured formatted time during which debugger is in a (Not Responding) mode...

This time again, the unresponsive error message is no longer appearing... but that may be because of JavaScript execution load balancing (set to improve performance) between various core execution of TB which cause the script/function to be interrupted possibly at regular interval (below the threshold that raise the error) before being continued...

Once the response is loaded and UI available again, when switching between Debugger tab and Network tab, a lot of delays appear with again the (Not Responding) suffix appearing in the Dev Tools title bar...

Also noticed, if I try to press the Pause button in Debugger tab, TB still seems to continue running some how in the background some items keep appearing in the calendar item list, etc... while I would expect the application to have paused by pressing the pause button in Debugger.

Finally it seems sometime is is also not possible to Pause in the Debugger tab, clicking on button having not effect with the following alt text appearing when mouse over: Waiting for next execution...

Will post some screenshots next for info...

Comment 12

[Richard Leger]

Attachment: Capture002-70seconde-prior-responsetext-appears.PNG

When clicking Network > REPORT > Response the result display area remain empty for 70seconds prior text appear in B&W colour...

Comment 13

[Richard Leger]

Attachment: Capture003-addional130seconds-prior-sameresponsetext-appears-colour-formatted.PNG

another 130seconds between the text appears in B&W colour and the same response text appears colour formatted...

Comment 14

[Richard Leger]

Attachment: Capture001-Waiting-for-next-execution-when-mouseover-pause-debugger-button.PNG

In Dev Tools > Debugger, when mousing over the Pause button, the text "Waiting for next execution" appears, when clicking the Pause button nothing seems to happen...

Comment 15

[Richard Leger]

Attachment: unresponsive.script,react.js.554.png

While the situation has improved slightly, there are still some issue when reading a REPORT request Response via devtools... see unresponsive script warning attached... in addition there is a note a the top of the response that says "the response has been truncated" or similar...

Comment 16

[Richard Leger]

Attachment: REPORT.request.response.Poor.Netowork.Timing.png

Performance/Timing wise, it seems also very poor... see attached... 12000ms to load REPORT Request Response? I suspect it might be delay due to parsing of the response... and I suspect if it is happening in the devTools, the same would be happening within TB when it loads calendar and parse events from the response REPORT bathes... If this issue was to be looked after and sorted, it may greatly solved performance issues with calendar loading as currently encountered... at least part of it...

Comment 17

[Richard Leger]

Could it be a bug in ressource://devtools/client/shared/vendor/react.js:554 third-party library code? Or when parsing data into DOM objects...?

Comment 18

[Richard Leger]

Would someone have some advise on how to re-run one of the REPORT request in Firefox to compare? Or its devtools instead of TB? Could not find out how to do it...

Comment 19

[Richard Leger]

Attachment: unresponsive.script.codemirror.bundle.js.1.png

I managed to re-run the same REPORT query in Firefox 66.0.3 devtools and the request take about 5000ms to complete (5 seconds! still way too long in term of timing)... when trying to read the XML response, it takes time to shows up with an Unresponding notice appearing for a short while and the attached unresponsive script alert popping up at some point... It does not show truncated file alert though...

Unresponsive script
Script: chrome://devtools/content/sour...odemirror/codemirror.bundle.js.1

Comment 20

[Richard Leger]

If I press Continue each time the Unresponsive script popup comes up, at some point after 4 or 5 times, the processing completes and the Response appears as coloured formatted (was appearing B&W at first).

The response is an XML file with 31000 lines!!! No wonder why it takes time to format!!!

Correction: In my previous comment I meant "Not Responding notice" instead of "Unresponding notice"...

Comment 21

[Richard Leger]

(In reply to Richard Leger from comment #15)

... in addition there is a note a the top of the response that says "the response has been truncated" or similar...

I found an answer about the "truncated" response notice mystery here...
Bug 1159078 Display a useful message when a response body is truncated

There is a 1MB response logging limit in devtools above which the response is truncated... Indeed if I copy past the response, via devtools I can see clearly towards the end that that xml file was truncated... as there are missing closing tags... but obviously that applies only to logged data and not the response itself...

Comment 22

[Wayne Mery (:wsmwk)]

Richard does this still reproduce with a current beta?

Comment 23

[Richard Leger]

A priori resolved as I cannot reproduce the issue in TB 90.0b3 (64-bit).