Closed Bug 1448184 Opened 6 years ago Closed 6 years ago

Only notify of batch operations in the history engine when we have updates to apply

Categories

(Firefox :: Sync, defect, P2)

Product:
Firefox
Component:
Sync
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 61
Tracking Flags:
Tracking Status
firefox61 --- fixed

People

(Reporter: markh, Assigned: markh)

Details

Attachments

(2 files)

Bug 1448184 - only send notifications of history batch updates when we actually have updates.
59 bytes, text/x-review-board-request
tcsc
: review+
Details
insertMany.js scratchpad
1.07 KB, application/x-javascript
Details 
The Sync history engine notifies of onBeginUpdateBatch and onEndUpdateBatch, but calls PlacesUtils.history.insertMany() to insert the visits. I'd like to remove the batch notifications because:

* Now that insertMany exists, any optimizations desired to handle bulk updates should be done by insertMany itself.

* Nothing seems to care about the notifications.

* For some obscure reason, removing these notifications means I can no longer reproduce bug 697649.

Mark, I'm going to flag you for review, mainly for you to confirm that no harm will come from this change.
Assignee: nobody → markh
Nothing obscure, not notifying a batch won't rebuild the whole tree, and thus it won't cause us to lose and restore selection (and editing). We always knew the reason for that bug were batches.

The only problem is that inserting a lot of visits while an history view is open, will be more expensive. I can't predict how much slower, so it may be useful to do some measurements on a normally-large profile (what you use everyday would probably do).
We can't optimize a lot nowadays in views because notifications are still horrible, that's what Doug is working on in bug 1340498 and until we have that it's unlikely we can make the view pick better decisions.

So, I suggest doing some measurements of a large addition with the history sidebar open, with and without notifying the batch, and see how much we're losing. IIRC sync has an upper limit to the number of visits added, so that limit could be what to measure.
Comment on attachment 8961600 [details]
Bug 1448184 - only send notifications of history batch updates when we actually have updates.

https://reviewboard.mozilla.org/r/230462/#review236082

The patch looks sane, but cancelling review pending discussion/investigations.
Attachment #8961600 - Flags: review?(standard8)
I used this scratchpad to insert 500 visits, which is how Sync chunks visits, done with the history sidebar open. On my machine, the average time for the script to complete is 97ms  when notifications are sent, and 125ms when notifications aren't sent.

So while it seems quite fast, it still seems worthwhile. However, I think this is best done by PlacesUtils.history itself - so I'll submit a patch that adds the notification to places and removes it from sync.
Priority: -- → P2
Comment on attachment 8961600 [details]
Bug 1448184 - only send notifications of history batch updates when we actually have updates.

https://reviewboard.mozilla.org/r/230462/#review237088

::: toolkit/components/places/tests/history/test_insertMany.js:12
(Diff revision 2)
>  
> +function promiseObserveBatch() {
> +  return new Promise(resolve => {
> +    let sawBeginBatch = false;
> +
> +    let historyObserver = {

Please use `new NavHistoryObserver()` here, and adjust the code accordingly.
Attachment #8961600 - Flags: review?(standard8) → review+
Thanks Mark. Sadly this is giving me a bit of grief - there are a couple of test failures.

* One failure is in test_nsINavBookmarkObserver.js. While this initially looked like I just needed to add the new notifications to the test, the strange thing is that the *order* of notifications is not what I was expecting - the test sees onBeginUpdateBatch, onEndUpdateBatch and onItemVisited, in that order - which seems odd as the visit was added as part of a batch. See the most-recent patch for the these changes. I *think* the issue here has to do with the history update being made on a different thread and the order is wrong once the observer finds itself back on the main thread - but I'm not sure if there are other implications in that ordering.

* A second issue is even stranger - test_abstime-annotation-uri.js fails at line 140. nsNavHistoryResult.cpp appears to have support for the batch notifications but it's not clear to me why that isn't working as expected - it seems possible this is related to the "out of order" notifications seen above, but I'm really not sure. The patch has no attempt to fix that issue (as I really don't know what it is). I suspect refreshing the query would work, but clearly that shouldn't be necessary.

The latter issue worries me a little as Sync currently sends those notifications, so whatever the root cause is might be triggered by Sync and cause obscure problems with queries that non-Sync users don't see.

Do you have any advice on those 2 issues?
Flags: needinfo?(standard8)
I think the history update is being made with several async operations.

https://searchfox.org/mozilla-central/rev/7e663b9fa578d425684ce2560e5fa2464f504b34/toolkit/components/places/History.cpp#3276-3278

InsertVisitedURIs is a runnable and updates the database in async fashion. That probably is alright, and has a callback at the end to notify completion *however* NotifyManyVisitsObservers is another runnable that gets dispatched back to the main thread:

https://searchfox.org/mozilla-central/rev/7e663b9fa578d425684ce2560e5fa2464f504b34/toolkit/components/places/History.cpp#1257-1259,1287-1289

We don't have a wait for completion on that, so I think that is why we're getting the notifications out of sequence.

For getting around this, my only thoughts are:

a) Have NotifyManyVisitsObservers do the batch notifications before/after, maybe on a threshold.
b) Wait until bug 1340498 lands with the history observer re-implementation which may make the need for batch updates go away, or may give a better location for batch updates (a quick glance at the patches, I'm not sure - would need to understand them more).

Marco may have other ideas.
Flags: needinfo?(standard8)
Thanks for the reply.

(In reply to Mark Banner (:standard8) (afk until 3rd April) from comment #9)
> I think the history update is being made with several async operations.

Yeah, that's my understanding too.

However, the second issue I mentioned above doesn't have an obvious answer that's related to the async operations.

> For getting around this, my only thoughts are:
> 
> a) Have NotifyManyVisitsObservers do the batch notifications before/after,
> maybe on a threshold.
> b) Wait until bug 1340498 lands with the history observer re-implementation
> which may make the need for batch updates go away, or may give a better
> location for batch updates (a quick glance at the patches, I'm not sure -
> would need to understand them more).
> 
> Marco may have other ideas.

I think I'll just abandon this approach and make this a sync-only change.
Summary: Don't notify of batch operations in the history engine → Only notify of batch operations in the history engine when we have updates to apply
Comment on attachment 8961600 [details]
Bug 1448184 - only send notifications of history batch updates when we actually have updates.

https://reviewboard.mozilla.org/r/230462/#review239306

Sorry, I think there's another yak to shave around deletions now, although if you can convince me we shouldn't do that now I *might* be able to be convinced.

::: services/sync/modules/engines/history.js:221
(Diff revision 4)
>        let record = records[k] = records[i];
>        let shouldApply;
>  
>        try {
>          if (record.deleted) {
>            await this.remove(record);

This no longer happens inside the batch. I don't know the intended semantics of `on{Begin,End}UpdateBatch`, but it seems something between confusing and suboptimal to do that. (Admittedly, history tombstones *are* rare, so this probably doesn't matter much).

I think probably we want to add it into an array and process them all at once where we do the other updates (Worth noting that `PlacesUtils.history.remove()` can take an array of GUIDs, which seems to be more efficient, since it does the operation in 1 DELETE instead of N, although as mentioned, history tombstones are rare enough that this seems unlikely to matter).

::: services/sync/modules/engines/history.js:250
(Diff revision 4)
> +      let observers = PlacesUtils.history.getObservers();
> +      function notifyHistoryObservers(notification) {
> +        for (let observer of observers) {
> +          try {
> +            observer[notification]();
> +          } catch (ex) { }

I know it was like this before, but I think we probably want to at least log if an observer throws.

::: services/sync/modules/engines/history.js:271
(Diff revision 4)
>          } catch (ex) {
>            this._log.info("Failed to insert history records", ex);
>          }
>        }
> +
> +      notifyHistoryObservers("onEndUpdateBatch");

Hm, this used to be in a finally block, and `_generateChunks` *can* throw if we're shutting down. This probably doesn't matter, though, and I'm commenting to make a note of it more than anything.
Attachment #8961600 - Flags: review?(tchiovoloni)
(In reply to Thom Chiovoloni [:tcsc] from comment #12)
> Sorry, I think there's another yak to shave around deletions now, although
> if you can convince me we shouldn't do that now I *might* be able to be
> convinced.

No, you are correct - nice catch.

> (Worth noting that
> `PlacesUtils.history.remove()` can take an array of GUIDs, which seems to be
> more efficient, since it does the operation in 1 DELETE instead of N,
> although as mentioned, history tombstones are rare enough that this seems
> unlikely to matter).

And the semantics of this seem quite dumb - a single invalid GUID will throw. So yeah, I still do it one at a time, but added a comment about doing them in one call.
It would also seem trickyis would make it difficul

> I know it was like this before, but I think we probably want to at least log
> if an observer throws.

PlacesUtils itself also ignores them, but yeah, it's a cheap addition.

> Hm, this used to be in a finally block, and `_generateChunks` *can* throw if
> we're shutting down. This probably doesn't matter, though, and I'm
> commenting to make a note of it more than anything.

Yeah, fair enough too.

Thanks!
Comment on attachment 8961600 [details]
Bug 1448184 - only send notifications of history batch updates when we actually have updates.

https://reviewboard.mozilla.org/r/230462/#review239964


Code analysis found 1 defect in this patch:
 - 1 defect found by mozlint

You can run this analysis locally with:
 - `./mach lint path/to/file` (JS/Python)


If you see a problem in this automated review, please report it here: http://bit.ly/2y9N9Vx


::: services/sync/modules/engines/history.js:215
(Diff revision 5)
> -      let record = records[k] = records[i];
> -      let shouldApply;
> -
> -      try {
> -        if (record.deleted) {
> +      if (record.deleted) {
> -          await this.remove(record);
> +        toRemove.push(record)

Error: Missing semicolon. [eslint: semi]
Comment on attachment 8961600 [details]
Bug 1448184 - only send notifications of history batch updates when we actually have updates.

https://reviewboard.mozilla.org/r/230462/#review240290

Thanks, this looks good.
Attachment #8961600 - Flags: review?(tchiovoloni) → review+
Pushed by mhammond@skippinet.com.au:
https://hg.mozilla.org/integration/autoland/rev/9bff182dc722
only send notifications of history batch updates when we actually have updates. r=standard8,tcsc
oops - sorry about that.
Flags: needinfo?(markh)
Pushed by mhammond@skippinet.com.au:
https://hg.mozilla.org/integration/autoland/rev/d07aaff2c4e1
only send notifications of history batch updates when we actually have updates. r=standard8,tcsc
https://hg.mozilla.org/mozilla-central/rev/d07aaff2c4e1
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox61: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 61
This apparently caused my history sincing to break with

1525952356859	Sync.ErrorHandler	DEBUG	history failed: TypeError: this is undefined (resource://services-sync/engines/history.js:242:13) JS Stack trace: notifyHistoryObservers@history.js:242:13
applyIncomingBatch@history.js:246:7
async*_applyRecords@engines.js:1415:29
async*_processIncoming@engines.js:1205:33
async*_sync@engines.js:1837:13
async*WrappedNotify@util.js:179:27
async*sync@engines.js:900:12
async*_syncEngine@enginesync.js:214:13
async*sync@enginesync.js:156:21
async*onNotify@service.js:1131:13
async*WrappedNotify@util.js:179:27
async*WrappedLock@util.js:135:22
async*_lockedSync@service.js:1124:12
async*sync/<@service.js:1116:13
async*WrappedCatch@util.js:105:22
async*sync@service.js:1105:12
async*doSync/<@browser-sync.js:594:46
Flags: needinfo?(markh)
That should be fixed by bug 1460396, I think.
Flags: needinfo?(markh)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: