Open Bug 1485480 Opened 3 years ago Updated 3 years ago

Frecency recalculation query in bookmarks mirror takes over 6 seconds

Categories

(Toolkit :: Places, defect, P5)

defect

Tracking

()

People

(Reporter: lina, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: stalled)

From bug 1472963, comment 23:

> This time telemetry shows this SQL statement: 
> UPDATE moz_places SET frecency = CALCULATE_FRECENCY(id) WHERE id IN ( SELECT id FROM moz_places WHERE frecency < 0 ORDER BY frecency ASC LIMIT :limit ) /* places.sqlite */ 
>
> It easily takes over 6000 ms.

I don't think Sync logs are going to help much here, unfortunately. :-(

TMart, would you mind running `CALCULATE_FRECENCY(id) WHERE id IN ( SELECT id FROM moz_places WHERE frecency < 0 ORDER BY frecency ASC LIMIT 400 )` from the SQL tab About Sync, and seeing if you notice a similar hang? Thanks!

It would also be great to see the output of `EXPLAIN QUERY PLAN` for that query, along with:

* `SELECT count(*) FROM moz_places WHERE frecency < 0`, to see how many URLs need new frecencies, and...
* `SELECT count(*) FROM moz_places`, for total URLs.
Flags: needinfo?(Tobias.Marty)
See Also: → 1472963
Blocks: 1433177
I would love to, unfortunately about:sync doesn't load for me anymore with the addon (version 0.0.23) enabled. I have no idea why that is.
(In reply to TMart from comment #1)
> I would love to, unfortunately about:sync doesn't load for me anymore with
> the addon (version 0.0.23) enabled. I have no idea why that is.

I hope to have that fixed very soon.
(In reply to Lina Cambridge (she/her) [:lina] from comment #0)
> TMart, would you mind running `CALCULATE_FRECENCY(id) WHERE id IN ( SELECT
> id FROM moz_places WHERE frecency < 0 ORDER BY frecency ASC LIMIT 400 )`
> from the SQL tab About Sync, and seeing if you notice a similar hang? Thanks!
This returns an error: 
Error running SQL: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [mozIStorageConnection.createStatement]" nsresult: "0x80004005 (NS_ERROR_FAILURE)" location: "JS frame :: chrome://aboutsync/content/build.js :: getSqlColumnNames :: line 27674" data: no]

> It would also be great to see the output of `EXPLAIN QUERY PLAN` for that
> query, along with:



> * `SELECT count(*) FROM moz_places WHERE frecency < 0`, to see how many URLs
> need new frecencies, and...
33

> * `SELECT count(*) FROM moz_places`, for total URLs.
133219
Flags: needinfo?(Tobias.Marty)
(In reply to TMart from comment #3)
> This returns an error: 
> Error running SQL: [Exception... "Component returned failure code:
> 0x80004005 (NS_ERROR_FAILURE) [mozIStorageConnection.createStatement]"
> nsresult: "0x80004005 (NS_ERROR_FAILURE)" location: "JS frame ::
> chrome://aboutsync/content/build.js :: getSqlColumnNames :: line 27674"
> data: no]

Oops, sorry, I accidentally a statement. :-O

UPDATE moz_places SET frecency = CALCULATE_FRECENCY(id) WHERE id IN ( SELECT id FROM moz_places WHERE frecency < 0 ORDER BY frecency ASC LIMIT 400

> > * `SELECT count(*) FROM moz_places`, for total URLs.
> 133219

Hmm, that's not many URLs. Do you see any other statements in telemetry? We might be waiting for another to finish.
(In reply to Lina Cambridge (she/her) [:lina] from comment #4)
> Oops, sorry, I accidentally a statement. :-O
> 
> UPDATE moz_places SET frecency = CALCULATE_FRECENCY(id) WHERE id IN ( SELECT
> id FROM moz_places WHERE frecency < 0 ORDER BY frecency ASC LIMIT 400
Ok, that gives me 0 changes. 

> Hmm, that's not many URLs. Do you see any other statements in telemetry? We
> might be waiting for another to finish.
Not really. 

I can't really reproduce this right now, so it doesn't seem as bad as the problem I had before, which I could reproduce very easily. Maybe I triggered a worst case scenario somehow that happens only rarely. 

I will keep this ticket in mind however if I notice it again.
Just had another main process freeze while clicking on the Library button, then Downloads, after setting a few bookmarks. 

This statement shows up in telemetry: 
SELECT h.id, h.url, h.title AS page_title, h.rev_host, h.visit_count, h.last_visit_date, null, null, null, null, null, null AS tags , h.frecency, h.hidden, h.guid, null, null, null FROM moz_places h WHERE 1 AND hidden = 0 AND last_visit_date NOTNULL AND ( h.id IN (SELECT place_id FROM moz_historyvisits WHERE visit_type = :transition0_ ) ) ORDER BY 6 DESC LIMIT 42 /* places.sqlite */
Unfortunately it looks like the common "main-thread IO is unpredictable" problem, where the disk may be busy doing something else and then any operation, even a fast one, can take seconds to complete :(
Keywords: stalled
Priority: -- → P5
You need to log in before you can comment on or make changes to this bug.