1511885 - Address book: Address search has become awfully slow

Status: RESOLVED FIXED

(Thunderbird :: Address Book, defect)

Description

[kenkamiya]

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.

Comment 1

[Wayne Mery (:wsmwk)]

Help > Restart with add-ons disabled make a difference?

Comment 2

[Jorg K (CEST = GMT+2)]

Yes, we identified the issue in TB 60.3.2 and will fix it in TB 60.3.3.

Comment 4

[Jorg K (CEST = GMT+2)]

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.

Comment 5

[Jorg K (CEST = GMT+2)]

Reporter, try this TB 60.3.3 preview executable:
https://queue.taskcluster.net/v1/task/T7s4g6X4TDOyFMxyWd36aA/runs/0/artifacts/public/build/install/sea/target.installer.exe

Comment 6

[:aceman]

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).

Comment 7

[Geoff Lankow (:darktrojan)]

The file is being written to disk every time a card is read from it. We can fix that.

Comment 8

[Geoff Lankow (:darktrojan)]

Attachment: 1511885-fix-commit-1.diff

Comment 9

[Jorg K (CEST = GMT+2)]

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

Aceman, can you please check this for speed.

Comment 10

[[e-mail]]

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.)

Comment 11

[Geoff Lankow (:darktrojan)]

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.

Comment 12

[[e-mail]]

(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.

Comment 13

[Ben Bucksch (:BenB)]

@Neil: can you do a review?

Comment 14

[[e-mail]]

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?

Comment 15

[[e-mail]]

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...)

Comment 16

[Geoff Lankow (:darktrojan)]

(In reply to [e-mail] 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

[:aceman]

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.

Comment 18

[Jorg K (CEST = GMT+2)]

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

[Jorg K (CEST = GMT+2)]

BTW, without the patch auto-complete went and added UIDs to the addresses it came across, so that explains the slowness.

Comment 20

[Geoff Lankow (:darktrojan)]

(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

[Jorg K (CEST = GMT+2)]

According to my testing, this could be an r+ unless I hear objections. Aceman, Neil, Ben?

Comment 22

[:aceman]

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?

Comment 23

[Jorg K (CEST = GMT+2)]

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.

Comment 24

[Jorg K (CEST = GMT+2)]

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?

Comment 25

[Geoff Lankow (:darktrojan)]

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.

Comment 26

[Ben Bucksch (:BenB)]

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.

Comment 27

[:aceman]

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.

Comment 28

[Jorg K (CEST = GMT+2)]

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

Let's take it. Missed TB 65, so beta+.

Comment 29

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/comm-central/rev/09c5f382dc15
Stop writing to disk every time a card is accessed. r=jorgk

Comment 30

[Jorg K (CEST = GMT+2)]

Beta (TB 65):
https://hg.mozilla.org/releases/comm-beta/rev/a2bd632a970bd5cd9988a6ba3812a0e09cbbd22b

Comment 31

[Geoff Lankow (:darktrojan)]

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.

Comment 32

[Jorg K (CEST = GMT+2)]

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.

Comment 33

[Wayne Mery (:wsmwk)]

Where is the try build?

Comment 34

[Jorg K (CEST = GMT+2)]

There isn't one yet, I can make one and post it here. Windows?

Comment 35

[Wayne Mery (:wsmwk)]

(In reply to Jorg K (GMT+1) from comment #34)
> Windows?

Yes please - all the reports are windows

Comment 36

[Jorg K (CEST = GMT+2)]

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.

Comment 37

[Wayne Mery (:wsmwk)]

https://support.mozilla.org/questions/1242697 reports good results

Comment 38

[Jorg K (CEST = GMT+2)]

TB 60.4.0 ESR:
https://hg.mozilla.org/releases/comm-esr60/rev/a85161ecb5ead8f46cd51a37494a9501c5ae8aaa

Comment 39

[Jorg K (CEST = GMT+2)]

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

Comment 40

[Geoff Lankow (:darktrojan)]

Yeah, that'll be it.

Comment 41

[Jorg K (CEST = GMT+2)]

TB 60.4.0 ESR (follow-up):
https://hg.mozilla.org/releases/comm-esr60/rev/945fb5fce3d3b44de337fabe8d962eee201f6a8b