1396364 - Bad performance browser.bookmarks.getChildren on folders with subfolders containing many bookmarks

Status: NEW

(WebExtensions :: General, defect, P3)

Description

[John]

User Agent: Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0
Build ID: 20170902100317

Steps to reproduce:

It looks like this function get subtree and then removed childrens. I think this is knowed problem but it's not reflected on bugzilla.

Comment 1

[aafn]

Hello, I don't want to argue too much, but how can this be a P3 ? This is rendering browser.bookmarks.getChildren() completely impracticable ..

Context:
- I wrote an add-on for managing search on bookmark = Bookmark Search Plus 2 -> https://addons.mozilla.org/fr/firefox/addon/bookmark-search-plus-2/
- One of my user has nearly 80000 bookmarks + 15000 folders -> https://github.com/aaFn/Bookmark-search-plus-2/issues/5
- This is lasting around 25s on his system to execute a getTree() (or getSubtree("root________"), this is the same)
- I generated 60000 bookmarks and 15000 folders on my FF, and the same query is taking around 825s to load on my system !!
    Just the API call ... and my system is not a por one, this is an i7 kabylake 4500 MHz.
- And during *all* that time, the one core allocated to my FF javascript process is at 100% !

So I started to work on using splitting by pieces so that I could display the bookmark tree only for open pieces, and load the hidden ones in background, so that my user could be operating on his bookmarks very fast, on the premise that only a small par t of the tree is open and visible.

Only way is browser.bookmarks.getChildren()
But since this is taking as long as the full call, I can't use it .. this is simply making things worse by a factor of 15000 !!

Here are some traces of my add on with additional test code, on 60000 bookmarks and 15000 folders, to help:
(I included bookmarks.get() for reference)

>PlatformOs: win
>Setting Windows variations
>Load duration: 827444 ms
>Display duration: 11471 ms
>fontFamily = '"Segoe UI"'
>fontSize   = '12px'
>Save duration: 53 ms
>Stats:
>------
>Bookmarks:  61103
>Folders:    15285
>Separators: 4
>--------------------
>Root get duration: 6 ms
>      Root.children: undefined
>Root getChildren duration: 825553 ms
>      Number of children: 4
>Root getSubTree duration: 824053 ms
>      Root.children: [object Object],[object Object],[object Object],[object Object]
>      Number of children: 4
>(Root) getTree duration: 827584 ms
>      Root.children: [object Object],[object Object],[object Object],[object Object]
>      Number of children: 4


And here is the code for the above measurements:


>const Root = "root________";
>browser.bookmarks.get(Root)
>.then(
>  function (BTN) {
>    var t2 = new Date();
>    trace("Root get duration: "+(t2.getTime() - startTime.getTime())+" ms");
>    trace("      Root.children: "+BTN.children);
>    browser.bookmarks.getChildren(Root)
>    .then(
>      function (a_BTN1) {
>        var t3 = new Date();
> 	 trace("Root getChildren duration: "+(t3.getTime() - t2.getTime())+" ms");
> 	 trace("      Number of children: "+a_BTN1.length);
> 	 browser.bookmarks.getSubTree(Root)
> 	 .then(
> 	   function (a_BTN2) {
> 	     var t4 = new Date();
> 	     trace("Root getSubTree duration: "+(t4.getTime() - t3.getTime())+" ms");
> 	     trace("      Root.children: "+a_BTN2[0].children);
> 	     trace("      Number of children: "+a_BTN2[0].children.length);
> 	     browser.bookmarks.getTree()
> 	     .then(
> 	       function (a_BTN3) {
> 	     	 var t5 = new Date();
> 	 	 trace("(Root) getTree duration: "+(t5.getTime() - t4.getTime())+" ms");
> 	 	 trace("      Root.children: "+a_BTN3[0].children);
> 	 	 trace("      Number of children: "+a_BTN3[0].children.length);
> 	       }
> 	     );
> 	   }
> 	 );
>      }
>    );
>  }
>);

I am on Firefox 58.0.2.

What can we do to get this way better, please, and I can help, let me know.
Thank you in advance, Aafn.

Comment 2

[aafn]

Attachment: This is a set of nearly 60000 bookmarks and 15000 folders to import, it will create a "Big load" folder under "Bookmarks menu" containing all these for the purpose of tests (easy to delete afterwards)

This is a set of nearly 60000 bookmarks and 15000 folders to import.
It will create a "Big load" folder under "Bookmarks menu" containing all these for the purpose of tests (easy to delete afterwards).

Comment 3

[Marco Bonardo [:mak]]

I'll see if next week I can find some time for profiling this.

Comment 4

[Mark Banner (:standard8)]

(In reply to aafn from comment #1)
> Hello, I don't want to argue too much, but how can this be a P3 ? This is
> rendering browser.bookmarks.getChildren() completely impracticable ..

Somewhere around move than 95% of our users have less than 2000 bookmarks. Whilst we recognise a few users do have big bookmarks stores, we generally have to prioritise based on most of our users. That doesn't mean we don't want to improve the speed (and we have been actively working on improvements for the last few versions), but we do have to balance it when we get issues with large stores.

> So I started to work on using splitting by pieces so that I could display
> the bookmark tree only for open pieces, and load the hidden ones in
> background, so that my user could be operating on his bookmarks very fast,
> on the premise that only a small par t of the tree is open and visible.
> 
> Only way is browser.bookmarks.getChildren()
> But since this is taking as long as the full call, I can't use it .. this is
> simply making things worse by a factor of 15000 !!

I think your problem here is that the root of the bookmarks tree contains 4 roots only - "Bookmarks Menu", "Bookmarks Toolbar", "Other Bookmarks" and "Mobile Bookmarks".

In your code you are effectively doing this:

browser.bookmarks.get(Root)
browser.bookmarks.getChildren(Root)
browser.bookmarks.getSubTree(Root)
browser.bookmarks.getTree()

The first just gets the root folder itself, with no children, hence nice and quick.

getTree() is the same as getSubTree(Root) - they're returning the same things, so we'd expect them to take about the same amount of time.

getChildren(Root) is obviously at issue here. It is using PlacesUtils.promiseBookmarksTree to get everything underneath the root. It then does some post filtering to return only the children.

A partial improvement might be to use promiseBookmarksTree filtering mechanism to filter out the non-required items ahead of time, however the sql query is still likely to be getting the full set and probably taking most time (although there's some additional synchronous queries I think we could avoid).

To fix the query, it might be better for us to proceed with implementing PlacesUtils.bookmarks.fetchTree (bug 1081106) and allowing this children-only option there, I may need fetchTree for a different bug anyway.

I'll see if I can get some estimates for the partial improvement. I'll leave the NI here for Marco in case he wants to look at this analysis further.

Comment 5

[Mark Banner (:standard8)]

I did some experimentation with the html file attached here imported. The SQL query in promiseBookmarksTree is taking around 12 minutes, the extraction from the sql results to the item tree is about 6 seconds.

The expensive part of the SQL query in promiseBookmarksTree appears to be the tags extraction for each item: https://searchfox.org/mozilla-central/rev/f860c2bf00576959b07e2d9619c7b5088b0005be/toolkit/components/places/PlacesUtils.jsm#1816-1820

If I take that out, then the SQL query ends up around a couple of seconds. If we're not able to optimise it further, we might need to wait for bug 424160 which we're actively working towards, and improves the storage mechanism for tags.


Marco: is possible to optimise the tags extraction in SQL, or would it be better waiting for bug 424160?

Comment 6

[aafn]

Thank you much for looking into this :-)
That is enlightening.

Basic question and please forgive me if this is stupidly simple to answer for somebody knowing the code and the table structure, but I do not have my ways in navigating FF source code to find it, and I do not know places either:

I suppose there is an index on the moz_bookmarks.id field, that would only seem obvious, but is there one on moz_bookmarks.parent ?

Since we're doing t.id = +b2.parent  and  t.parent = :tags_folder, so selecting twice on the parent field, if there is no index on it, having one would improve speed significantly I would guess.
(note: I do suppose there's one naturally on moz_bookmarks.fk as I interpret its name to be "foreign key" ??)

Btw, am I right in understanding that tags are stored in the same table than bookmarks, as moz_bookmarks records being "children" of a special bookmark record for holding tags ?
If yes, indeed extracting tags in a separate table as mentioned in bug 424160 should do a lot as it would allow to browse much less records to get them, and to have more optimized indexes I suppose.

Comment 7

[Marco Bonardo [:mak]]

tags extraction slows down a lot of queries, we can't do anything for now. The good thing is that a minority of users has many bookmarks, and a minority of that minority has tags...
No reason to re-analyze the tags situation or the schema, we already know it sucks.

Comment 8

[John]

> To fix the query, it might be better for us to proceed with implementing PlacesUtils.bookmarks.fetchTree (bug 1081106) and allowing this children-only option there

Comment 9

[aafn]

Hello gents, my current performance measurements seem to show that, all things equal on the rest, 61.0.1 is degrading performances of browser.bookmarks.get(Root) by around 15 to 20%
=> making it longer than before by that proportion.

Am I correct ?

Would that be due to https://bugzilla.mozilla.org/show_bug.cgi?id=1472127 ?

Thanks, aaaFn.

Comment 10

[Mark Banner (:standard8)]

(In reply to aafn from comment #9)
> Hello gents, my current performance measurements seem to show that, all
> things equal on the rest, 61.0.1 is degrading performances of
> browser.bookmarks.get(Root) by around 15 to 20%
> => making it longer than before by that proportion.
> 
> Am I correct ?

Did you use the HTML file attached here to test, or your own database?

I'm asking, as the only thing I can see that changed around that function in 61.x is bug 1047819 - this changed annotation loading to happen asynchronously rather than synchronously. Whilst that helps avoids jank, it will also be likely to slow down the import due to the async nature.

The HTML file here doesn't have any annotations though as far as I can tell, so I doubt that would show any regression.

The good news is that we're working on removing annotations completely (bug 1460577), though that may take a few more months to complete.

Comment 11

[John]

I used own database, but I don't know anything about 61.x

Comment 12

[aafn]

Hello, this time I was using my own day to day database, and not the attached file.
My add on has detailed stats on load times, I use it every day instead of native bookmark sidebar, and I activate the traces by default as I need to follow up effects of my developments.

When upgrading to 61.0.1, and no change on the add on, I saw my measurements jump from around 260 ms to around 310 ms for the same set of around 2000 bookmarks.

Note that I do not have any annotation, tag or keyword in my bookmarks.

Comment 13

[Mark Banner (:standard8)]

(In reply to aafn from comment #12)
> When upgrading to 61.0.1, and no change on the add on, I saw my measurements
> jump from around 260 ms to around 310 ms for the same set of around 2000
> bookmarks.

Thanks for the clarification. As the majority of users have 2000 bookmarks or less, that isn't terribly bad timing. We'd obviously like it to be less, but as mentioned previously we need to work on other areas before we can get there.

> Note that I do not have any annotation, tag or keyword in my bookmarks.

A description is also an annotation as are a few other small-usage items.