Open Bug 1543953 Opened 2 years ago Updated 2 months ago

Lightning network REPORT request receiving time too high (0.5 to 3 seconds per request) - Loading one ~4000 events network calendar takes more than 1 minute - 46 network requests required (isn't it too much?)

Categories

(Calendar :: Provider: CalDAV, defect)

Lightning 6.9
defect
Not set
normal

Tracking

(Not tracked)

UNCONFIRMED

People

(Reporter: richard.leger, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: perf)

Attachments

(8 files)

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

Steps to reproduce:

Start Thunderbird 67.0b1 (32 bits) for Windows with patch.v03 applied from Bug 1502923 with only one network CalDav calendar setup containing ~4000 items. No email setup. New profile. Before closing TB and restarting TB to measure, Find Events view was set to show All Events and sort items by Title column header.

[This bug was observed/uncovered while troubleshooting Bug 1502923]

Actual results:

Via TB devtools > Network - ~46 requests observed to load the all calendar - mostly REPORT request. The first few REPORT requests take the longest in term of wait and receiving response time - can varie from 0.5 seconds to 3 seconds in most cases (but has been observed sometime up to 12 seconds response time for one request!!!)

Via Task Manager > Performance > Wifi - You can see the numerous requests spreading over more than 1 minute time to complete the load of just one network calendar in TB.

Expected results:

The initial loading of the calendar data shall be much faster than observed and which much less network requests in number but maybe bigger in size.

When loading the entire calender via GET request as an .ics file it only takes a fraction of a second... so definitely not a calendar server issue here...

Find attached the Task Manager > Performance > Wifi graph showing the minute of request this was capture just before the calendar end loading... the all graph corresponds to most of the network requests used for loading the calendar...

Attached image devtools.network.png

Find attached the devtool > Network result - Too many requests - Too much time for each!!!

I suspect the request send by Lightning are not performant as they seems to look for each items and load each items in turn while it should just get the calendar as .ics file in one request and parse it (all items) to initialise the Calendar... that would be a much faster way to do... but may not be possible due to the nature of DavCal and the way it works.

FYI, find attached the calendar setting options (all unticked) used to run the tests.

Also increasing the calendar.caldav.multiget.batch.size option from 100 (default) to 200,400,600,1000 make no positive difference. Reducing it either...

Component: Untriaged → Provider: CalDAV
Product: Thunderbird → Calendar
Version: 67 → Lightning 6.9

Currently at startup, Thunderbird run a CalDAV sync on the calendar which mean:

  1. Get calendar feature and options
    ==> few first requests (x3)
    in less than one second

  2. Get a list of all etags and uri of EACH calendar objects (VEVENT, VTODO, etc...) - meaning ALL of them
    ==> 1 REPORT request - Which return an XML file of 32000 lines for ~4000 items!!!
    in ~12 seconds

  3. Send requests to sync each items one by one (really inefficient in the case where ALL calendar items need loading) by chunck of 100 (default value)
    => 42 REPORTS requests!!!
    in ~1 to ~2 seconds each

I think it would be more efficient to do the following at TB startup:

  1. Get calendar feature and options
  2. Get the full calendar as .ics file via a GET request instead and parse it
    This take only 2seconds with my 4000 items calendar
  3. Get the etag and uri for each calendar objects

and/or use a time range query to sync only the past 60 days and future 365 days at boot up... leaving the rest to be synched later on either when TB is idle or when user request it via the UI interface (time frame).

  1. Get calendar feature and options
  2. Get a list of all etags and uri of calendar objects (VEVENT, VTODO, etc...) within -60 days +365 days <-- this would be the initial timespan
  3. Send requests to sync each items within the time range one by one by chunk
    3bis - Reduce the quantity of data to be transferred by selecting only the minimum properties needed by the UI elements (e.g Title, Start Date, etc...) and disregarding what is not required (e.g Description, Attendees, Attachments, etc... - Those only need to be loaded when end-user edit the VEVENT or VTODO... which is already the case...)

Later on when idle (or upon request by end-user)

  1. do the same on the time frame -beginingOftime -60 days
  2. do the same on the timr frame +365 days +endOfTime(infinite)

As feature request, I would also suggest to provide additional UI calendar properties to end-users to define the following on per calendar bases:

  • chunk size - people with high speed connection could benefit from having higher chunk size to reduce the number of requests...
  • initial sync timespan past (e.g 60 days)
  • initial sync timespan future (e.g 365 days)
    I have created Bug 1544375 "Ligtning - Add network calendar UI options: Chunk size, Initial sync time range filters (sync timespan future and past)" to deal with it separately.
See Also: → 1502923

(In reply to Richard Leger from comment #7)

3bis - Reduce the quantity of data to be transferred by selecting only the minimum properties needed by the UI elements (e.g Title, Start Date, etc...) and disregarding what is not required (e.g Description, Attendees, Attachments, etc... - Those only need to be loaded when end-user edit the VEVENT or VTODO... which is already the case...)

Here is an example of minimum properties that may be required, but I don't know if it is possible within CalDAV protocol to limit data to only those properties at least during initial sync at startup... it seems to be possible according to RFC but haven't clearly understood how that would work as calling the calendar-data fields means you get all the data from the object including properties that you may not need (e.g description, attendees, attachments)... maybe possible via the same REPORT query that allow to get the etag and uri... to be explored perhaps... that would increase the query response size but may be workable if associated with a filter time range...

TB VEVENT

Calendar Name
UID
DTSTAMP
???ORGANIZER
Title SUMMARY
Start DTSTART
???Duration DURATION
Category CATEGORIES
Location LOCATION
Status STATUS
Reminder VALARM
Priority PRIORITY

End DTEND

TB VTODO

Calendar Name
UID
DTSTAMP
???SEQUENCE
Title SUMMARY
Start DTSTART
???Duration DURATION
Category CATEGORIES
Location LOCATION
Status STATUS
Reminder VALARM
Priority PRIORITY

Done
Due DUE
Due in
Completed COMPLETED
%Completed PERCENT-COMPLETE

Also TB developers shall keep in mind that the first thing TB users do after starting Thunderbird is to receive and read emails... email processing/actions shall prevail on calendar processing... and not the opposite way around as currently it is the case...

Currently at startup, even if I receive emails in my IMAP mailbox (no cache), I cannot read new email till all the calendars have been initially loaded (no cache either)... If I click on new email, it does not load in preview pane (or in new tab) till the calendars are fully loaded first (which takes 5mn)... that should not happen in ideal order of things :-)

Loading an IMAP email shall take priority/precedence over calendar loading/sync... as TB is more "muli-processing" now, that should become more possible...

This is also not helped by heavy mail folder activity at startup, causing lots of IO.

Much of said IO being on main thread, i.e. UI thread, and being synchronous IO - Bug 588952 - autosync should use new async folder opening to avoid extremely bad performance at startup or when reading messages with very big IMAP folders (like gmail All Mail)

Keywords: perf
See Also: → 1544375, 1247240
Summary: Lightning network REPORT request receiving time too high (0.5 to 3 seconds per request) - Loading one ~4000 events network calendar takes more than 1mn - 46 network requests required (isn't it too much?) → Lightning network REPORT request receiving time too high (0.5 to 3 seconds per request) - Loading one ~4000 events network calendar takes more than 1 minute - 46 network requests required (isn't it too much?)

(In reply to Wayne Mery (:wsmwk) from comment #10)

This is also not helped by heavy mail folder activity at startup, causing lots of IO.

The problem is that calendar loading "hijack" the main thread/UI so nothing else happens till calendar(s) loading has completed. You cannot access content of new emails for example. If you click on email, the preview pane remain "empty" the email content is not loaded... Not convenient, not "normal" behaviour expected... :-)

The Bug 1502923 also does not help in this regards as it drastically delay calendar loading, it could be added as blocking Bug 487832 "(tb-startupperf) [meta] Thunderbird startup performance issues"..

Much of said IO being on main thread, i.e. UI thread, and being synchronous IO - Bug 588952 - autosync should use new async folder opening to avoid extremely bad performance at startup or when reading messages with very big IMAP folders (like gmail All Mail)

It there a way for Lightning to also load CalDav calendars asynchronously? Using workers perhaps or else async feature of TB?
This way the calendar could load slowly each in a different thread ideally (or one dedicated calendar thread) in the background while keeping email feature available (e.g end-user reading new email received) at all time especially at startup where email may be the primary feature end-users access to read new emails...

Will the integration of calendar into Thundebird help reduce any of this responsiveness? In other words, since it will all be one code base, will that make it any easier to separate out the I/O or do the prioritization you are trying to do? If nothing else, this bug bug 1493008 should be noted here.

(In reply to Worcester12345 from comment #12)

Will the integration of calendar into Thundebird help reduce any of this responsiveness?

No - integration changes nothing and will not help. Not even the analysis.

(if you're going to post bug numbers please post as "bug NNN", not a link)

FYI, still 46 network requests in TB.70.0b2 to load one calDAV network calendar with about 4000 items...

Attached is devtools network request part 1...

... part 2 attached...

See also Bug 1572823...

May be time to look into this bug because reducing the number of network requests may drastically help reduce the time it take to load network calendar... (new test results available here https://bugzilla.mozilla.org/show_bug.cgi?id=1572823#c16 and here https://bugzilla.mozilla.org/show_bug.cgi?id=1572823#c19) each network request shall be able to load more than 100 items at a time especially on fast networks e.g 1GB connection.

The best may be for TB

  • to detect speed of network connection and adjust number of items it loads per network request consequently
  • or to let end-user choose the network request batch size...
  • or both!
See Also: → 1642292
Attached image image.png

FYI and the record...

As observed in TB 78.0b1 (64-bits), it still takes about 50 network requests to load one CalDAV calendar with 4000+ items...

See attached...

(In reply to Richard Leger from comment #7)

I think it would be more efficient to do the following at TB startup:

  1. Get the full calendar as .ics file via a GET request instead and parse it
    This take only 2seconds with my 4000 items calendar

Am I dreaming or I have been heard? What a surprise today! Yes, Yes, Yes... finally!

Just upgraded to TB 81.0b4 (64-bit) and testing loading my ~4000 items caldav network calendar... while measuring and monitoring I could see only one network request and I first thought... damn calendar loading is broken again?!

...but checking via DevTools > Networking...
...what a surprise!!!

The 50 multi-get request that have been hindering calendar loading performance for so long have now been replaced by one single GET request that load the entire .ics calendar at once!!! Oh my god! What a speed difference max 22 seconds top... (result obtained with new profile, no email, one caldav network calendar newly setup with ~4000 items)

  • Was it intended or an unintended side effect of something else implemented, corrected or removed?
  • Is that gonna be the new way?
  • Would that perf improvement "stick" from now on?
    Can someone confirm?

No info in the release note:
https://www.thunderbird.net/en-US/thunderbird/81.0beta/releasenotes/?uri=/thunderbird/releasenotes/&locale=en-US&version=81.0&channel=beta&os=WINNT&buildid=20200914232954

Nor could I find any changelog in the source code that may explain such change:
https://hg.mozilla.org/releases/comm-beta/log/a8ea452b9f4cc059a4afebaf5d54af4e72e4b5c4
If someone could point out perhaps the changeset related to this change?

If that is intended that is great, great, great news to all TB calendar users out there!
Thank you...

I keep dreaming for now... hoping someone would confirm this reality!

I have yet to test difference on startup performance with my current default profile!

(In reply to Richard Leger from comment #19)

I have yet to test difference on startup performance with my current default profile!

I just re-tested and bad news, my existing already set calendar in my default profile (that I also use for emails) does not behave in the same manner. When I enabled it and run the sync, instead of one GET request as described in my previous comment, it still generate multi-GET requests to sync and therefore still affected by Bug 1642292.

This suggest that to get the new behaviour and related performance the calendar needs either to be deleted/re-created from scratch or that settings in my current already set calendars may need some adjustments to benefit from new behaviour... I would expect TB to take care of that upon upgrade :-)

Any clue?

Flags: needinfo?(paul)

I new it was too good to be true!

Indeed it appears than when testing and obtaining result as per Comment 19, when creating a new profile and adding my network calendar, it was added as an ICS type calendar (read-only) not allowing me to choose CALDAV (read-write capable) while my pre-existing calendar in my default profile was in the past setup as a CALDAV calendar... that explain the difference in loading performance... and the one GET request (20s) for ICS vs multi-get REPORT requests (7+mn) for CALDAV...

Bottom line... back to square one!

I guess the fact that I cannot choose CALDAV type of network calendar when adding a new one in TB 81.0b4 (64-bit) on Windows is a new bug in itself :-)

Hm, this could be somewhat related to the work in bug 1663399. That is troubling that you expected a CalDAV calendar but got an ICS one instead. Can you please open a separate bug for that, with the steps to reproduce? Like, if possible can you indicate what you entered for username and location when setting up the calendar? Or if not the exact text, then the general shape of it? That may be causing it to detect ICS rather than CalDAV.

Flags: needinfo?(paul)

(In reply to Paul Morris [:pmorris] from comment #22)

Hm, this could be somewhat related to the work in bug 1663399. That is troubling that you expected a CalDAV calendar but got an ICS one instead. Can you please open a separate bug for that, with the steps to reproduce?

New Bug 1666036 has been created as per your request.

See Also: → 1666036

Needs new version:

" Version:
Lightning 6.9"

Still affect 78.x ESR and beyond...

(In reply to Richard Leger from comment #25)

Still affect 78.x ESR and beyond...

Have you tested with 82.0b2? 82.0b3 has been built but not yet made official on tb.net so maybe hold off a few days and test with that when it's released.

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