Address book: Address search has become awfully slow

RESOLVED FIXED in Thunderbird 66.0

Status

defect
RESOLVED FIXED
5 months ago
4 months ago

People

(Reporter: kenkamiya, Assigned: darktrojan)

Tracking

({perf, regression})

Thunderbird 66.0
Unspecified
All
Dependency tree / graph

Thunderbird Tracking Flags

(thunderbird_esr6064+ fixed, thunderbird65 fixed, thunderbird66 fixed)

Details

User Story

https://support.mozilla.org/en-US/questions/1242603
https://support.mozilla.org/en-US/questions/1242563
https://support.mozilla.org/en-US/questions/1242513
https://support.mozilla.org/en-US/questions/1242412
https://support.mozilla.org/en-US/questions/1242697

Attachments

(1 attachment)

(Reporter)

Description

5 months ago
User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:63.0) Gecko/20100101 Firefox/63.0

Steps to reproduce:

I entered part of the address name (e.g., abc???@???.com) to be searched.


Actual results:

The system froze for 12 to 15 seconds.
Then, the email list window, which was underneath the address book window popped up by itself.  As I manually put it behind the address book window, I saw the correct address in the address list window.
This happens every time I search the address book.


Expected results:

Address search response time used to be only a fraction of a second.
Now, every time I search an address, it takes 12 to 15 seconds before I see the address.
Help > Restart with add-ons disabled make a difference?
Component: Search → Address Book
Flags: needinfo?(kenkamiya)
Keywords: perf

Comment 2

5 months ago
Yes, we identified the issue in TB 60.3.2 and will fix it in TB 60.3.3.
Flags: needinfo?(kenkamiya)

Updated

5 months ago
Duplicate of this bug: 1512014

Updated

5 months ago
Blocks: 1482040, 1490626

Comment 4

5 months ago
TB 60.3.3 fixed via backouts:
https://hg.mozilla.org/releases/comm-esr60/rev/d6e310cff401f6945897aad017e4663dfc9f40cc
Backed out changeset 73ed0515afc2 (bug 1490626) for causing address book and auto-complete slowness (bug 1511885). a=backout
https://hg.mozilla.org/releases/comm-esr60/rev/e4d520b5dc17e8a0e3ba4d760556b1ba4aad4842
Backed out changeset a6e340fe4c07 and 7fe1827e6b39 (bug 1482040) for causing address book and auto-complete slowness (bug 1511885). a=backout

Geoff, Neil, Ben, can you check what went wrong here. I assume the address book went off allocating IDs to potentially thousands of addresses.
Flags: needinfo?(neil)
Flags: needinfo?(geoff)
Flags: needinfo?(ben.bucksch)

Comment 6

5 months ago
In my testing the build of 60.3.3 with the backouts runs autocomplete 3 times faster then a build without (a sample of 16000 cards in collected addresses).

Updated

5 months ago
User Story: (updated)
Keywords: regression
OS: Unspecified → All
(Assignee)

Comment 7

5 months ago
The file is being written to disk every time a card is read from it. We can fix that.
Flags: needinfo?(geoff)
(Assignee)

Comment 8

4 months ago
Assignee: nobody → geoff
Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
Attachment #9029547 - Flags: review?(jorgk)

Comment 9

4 months ago
Comment on attachment 9029547 [details] [diff] [review]
1511885-fix-commit-1.diff

Aceman, can you please check this for speed.
Attachment #9029547 - Flags: feedback?(acelists)
So basically the code wants to do a one-time update to give all cards UIDs, and this used to be done for all cards, and now you're only doing it when someone actually uses the UID? (Although I don't quite see why the slowdown doesn't go away after all of the UIDs have been generated.)
(Assignee)

Comment 11

4 months ago
No. The code was writing to disk every time a card was read from the database, whether it already had a UID or not.

I'm changing it to write to disk only if a card without a UID gets a UID because it was asked for. Which is a lot more sensible but (IIRC) something I couldn't make work at the time.
(In reply to Geoff Lankow from comment #11)
> No. The code was writing to disk every time a card was read from the
> database, whether it already had a UID or not.

And the cards are read on every search? I was thinking that InitCardFromRow would only run once per session.
@Neil: can you do a review?
Flags: needinfo?(ben.bucksch)
Oh, and one more question (I'm not Columbo, honest!): Now that you're generating card uuids lazily, shouldn't you remove the call to GetUID() in nsAddrDatabase::CreateNewCardAndAddToDB?
To answer my other question, cards are recreated all the time, for instance when switching from All Address Books to a specific address book. (Watching for notifications must have been a nightmare before cards had proper uids we could use to keep track of which was which...)
(Assignee)

Comment 16

4 months ago
(In reply to neil@parkwaycc.co.uk from comment #14)
> Oh, and one more question (I'm not Columbo, honest!): Now that you're
> generating card uuids lazily, shouldn't you remove the call to GetUID() in
> nsAddrDatabase::CreateNewCardAndAddToDB?

I want all *new* cards to have a UID immediately, because that's easier on the database than another operation to do it later. And if there's a WebExtension listening the UID will be created almost immediately anyway.

Comment 17

4 months ago
Comment on attachment 9029547 [details] [diff] [review]
1511885-fix-commit-1.diff

Review of attachment 9029547 [details] [diff] [review]:
-----------------------------------------------------------------

On trunk, I get strange results with this patch.
On first ever typing in the recipient after TB startup, the typing is slow (each character appears after a delay), but then the autocompletion is fast.
On every subsequest typing (of the same string), autocomplete is as slow as without the patch.

The addressbook .mab file is growing fast and looking into it it seems to me UIDs are added to every card on each access even to cards that already have one.
Attachment #9029547 - Flags: feedback?(acelists) → feedback-

Comment 18

4 months ago
Comment on attachment 9029547 [details] [diff] [review]
1511885-fix-commit-1.diff

Review of attachment 9029547 [details] [diff] [review]:
-----------------------------------------------------------------

On a new profile without anything in the address book I added debug to nsAbCardProperty::SetUID(). I saw my debug for every card I added. Then I stared TB 60 on the profile and added two addresses without UID, of course. Back in the local build, I edited those addresses and inspected the .mab file. I didn't see UIDs being added, also no debug. Wouldn't editing the card be an ideal moment to add the missing UID?

I tried auto-complete and my debug didn't show. I also switched between address books and didn't see my debug.

So I cannot confirm Aceman's or Neil's statements. Can you guys try again, maybe with:
NS_IMETHODIMP nsAbCardProperty::SetUID(const nsACString &aUID)
{
  printf("=== setting %s\n", PromiseFlatCString(aUID).get());

::: mailnews/addrbook/src/nsAbCardProperty.cpp
@@ +381,5 @@
> +
> +  nsCOMPtr<nsIAbManager> abManager = do_GetService(NS_ABMANAGER_CONTRACTID, &rv);
> +  NS_ENSURE_SUCCESS(rv, rv);
> +
> +  nsCOMPtr <nsIAbDirectory> directory = nullptr;

The CTOR does the right thing, please do not initialise to null. And lose the space before the <.

Comment 19

4 months ago
BTW, without the patch auto-complete went and added UIDs to the addresses it came across, so that explains the slowness.
(Assignee)

Comment 20

4 months ago
(In reply to Jorg K (GMT+1) from comment #18)
> Wouldn't editing the card be an ideal moment to add the missing UID?

Yes it would be good to do that in ModifyCard, but adding the missing UID calls ModifyCard meaning we get a second write to disk there. If I could add the UID without forcing a write I'd do that, but the connections between card and directory are so poor (hence hacking a string to even get to the directory) and I just don't want to make this more complicated. Especially since we want to take this patch to ESR.

Comment 21

4 months ago
According to my testing, this could be an r+ unless I hear objections. Aceman, Neil, Ben?
Flags: needinfo?(ben.bucksch)
Flags: needinfo?(acelists)

Comment 22

4 months ago
Strange, I can no longer see any difference with or without the patch, whether the slowness or accumulation of UIDs.
May anything else be landed in the area since about 6th Dec?
Flags: needinfo?(acelists)

Comment 23

4 months ago
Can you add the debug from comment #18. I see no UIDs being added during auto-complete with the patch, so it should be faster.
Flags: needinfo?(acelists)

Comment 24

4 months ago
Geoff, so when do the UIDs get added now? When a new card is created? And when else for cards that don't have one yet?
(Assignee)

Comment 25

4 months ago
When a new card is created, or for existing cards that don't have a UID already, when it is asked for – ie. when GetUID is called.
Neil wrote in comment 14:
> cards are recreated all the time, for instance when switching from All Address Books to a specific address book.

That's probably the cause of the slowness.

If you need any further help from us to move this on, please ask.
Flags: needinfo?(ben.bucksch)

Comment 27

4 months ago
Comment on attachment 9029547 [details] [diff] [review]
1511885-fix-commit-1.diff

Review of attachment 9029547 [details] [diff] [review]:
-----------------------------------------------------------------

OK, I had to start with a clean .mab file (without any uids) to see the effect.
Without the patch, there are like 15 uids added for each card when autocompleting and the file grows by megabytes.
With the patch, no uids are added when autocompleting and it is faster, takes 30% of the time.
Attachment #9029547 - Flags: feedback- → feedback+

Comment 28

4 months ago
Comment on attachment 9029547 [details] [diff] [review]
1511885-fix-commit-1.diff

Let's take it. Missed TB 65, so beta+.
Flags: needinfo?(neil)
Flags: needinfo?(acelists)
Attachment #9029547 - Flags: review?(jorgk)
Attachment #9029547 - Flags: review+
Attachment #9029547 - Flags: approval-comm-beta+

Comment 29

4 months ago
Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/09c5f382dc15
Stop writing to disk every time a card is accessed. r=jorgk
Status: ASSIGNED → RESOLVED
Last Resolved: 4 months ago
Resolution: --- → FIXED

Updated

4 months ago
Target Milestone: --- → Thunderbird 66.0
(Assignee)

Comment 31

4 months ago
Comment on attachment 9029547 [details] [diff] [review]
1511885-fix-commit-1.diff

We'd better put the other stuff back with this on top of it.
Attachment #9029547 - Flags: approval-comm-esr60?

Comment 32

4 months ago
Wayne, from all the people who complained on SUMO, could you please organise someone who is willing to try out a try build based on TB 60 ESR.
Flags: needinfo?(vseerror)
Where is the try build?
Flags: needinfo?(vseerror)

Comment 34

4 months ago
There isn't one yet, I can make one and post it here. Windows?
(In reply to Jorg K (GMT+1) from comment #34)
> Windows?

Yes please - all the reports are windows

Comment 36

4 months ago
https://queue.taskcluster.net/v1/task/FuO3BojNRGmpze6yXzFU9g/runs/0/artifacts/public/build/install/sea/target.installer.exe
https://queue.taskcluster.net/v1/task/FuO3BojNRGmpze6yXzFU9g/runs/0/artifacts/public/build/target.zip

This is a preview version of TB 60.4.0 which had the patches which caused the slowness re-applied, additionally the patch here which is supposed to fix the issue.

This is safe to run on production data, you can either unpack the ZIP file and run thunderbird.exe from the DOS command line, or use the installer. You can install into a different directory and use TB 60.3.3 and TB 60.4.0 in parallel.

Over to you, Wayne.
Flags: needinfo?(vseerror)
https://support.mozilla.org/questions/1242697 reports good results
Flags: needinfo?(vseerror)

Updated

4 months ago
Attachment #9029547 - Flags: approval-comm-esr60? → approval-comm-esr60+

Comment 39

4 months ago
Hmm, comm/mailnews/addrbook/test/unit/test_uid.js fails on ESR. Does that need similar treatment like
https://hg.mozilla.org/releases/comm-esr60/rev/707388b59cb577cad0242f36bfa15d902ff65408#l1.30
Flags: needinfo?(geoff)
(Assignee)

Comment 40

4 months ago
Yeah, that'll be it.
Flags: needinfo?(geoff)
You need to log in before you can comment on or make changes to this bug.