Find bar uses sync IPC on each keypress

RESOLVED FIXED in Firefox 61

Status

()

Toolkit
Find Toolbar
RESOLVED FIXED
a year ago
3 months ago

People

(Reporter: Ehsan, Assigned: Gijs)

Tracking

(Depends on: 1 bug, Blocks: 1 bug, {perf})

unspecified
mozilla61
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox61 fixed)

Details

(Whiteboard: [qf:p3][fxperf:p1])

MozReview Requests

()

Submitter Diff Changes Open Issues Last Updated
Loading...
Error loading review requests:

Attachments

(1 attachment)

(Reporter)

Description

a year ago
See the code: <https://searchfox.org/mozilla-central/rev/a798ee4fc323f9387b7576dbed177859d29d09b7/toolkit/content/browser-content.js#867>

The mean time of this event is 0.98 so it's pretty low but 62% of sessions are sending it which suggests a lot of people do hit it.  It'd be nice to avoid it if possible.
(Reporter)

Comment 1

a year ago
Mike, is there something which we can do about this?
Flags: needinfo?(mdeboer)
Whiteboard: [qf]
Yes, I think it's possible, but it'd require more findbar state and implementation to be sync'ed or moved to the content process. Wrt opening the findbar using quickfind shortcuts I think that's a good idea regardless.
Flags: needinfo?(mdeboer)
I think Ehsan means .98ms so not P1
Whiteboard: [qf] → [qf:p3]
(Assignee)

Updated

4 months ago
Depends on: 1358815
(Assignee)

Updated

4 months ago
Assignee: nobody → gijskruitbosch+bugs
Status: NEW → ASSIGNED
(Assignee)

Updated

4 months ago
Whiteboard: [qf:p3] → [qf:p3][fxperf:p1]
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)

Comment 7

4 months ago
mozreview-review
Comment on attachment 8963339 [details]
Bug 1371523 - remove find bar sync ipc message,

https://reviewboard.mozilla.org/r/232232/#review237958

Yay! I'm also very happy with the code simplifications, in the tests as well. I truly hope the test failure comes down to something simple!

::: toolkit/content/browser-content.js:965
(Diff revision 2)
>  
>    /**
> +   * The key used for the find command ("f" for accel-f in English)
> +   */
> +  get _findKey() {
> +    let data = Services.cpmm.initialProcessData;

nit: Can you pass down the modifiers as well? This way we can keep the definitions/ constants in one place. The method below needs to be made a little smarter, though.

::: toolkit/content/browser-content.js:1059
(Diff revision 2)
>        if (typeof event[k] != "object" && typeof event[k] != "function" &&
>            !(k in content.KeyboardEvent)) {
>          fakeEvent[k] = event[k];
>        }
>      }
> -    // sendSyncMessage returns an array of the responses from all listeners
> +    sendAsyncMessage("Findbar:PassKey", fakeEvent);

nit: 'Findbar:Keypress' still works for me, which mirrors 'Findbar:Mouseup' as used below or 'Findbar:PassKeypress' might be a bit clearer.
Now I'm reminded of encryption passkeys. Pedantic, I know! :-P

::: toolkit/content/widgets/findbar.xml:910
(Diff revision 2)
>          <body><![CDATA[
>            if (this._browser && this._browser.messageManager) {
>              this._browser.messageManager.sendAsyncMessage("Findbar:UpdateState", {
> -              findMode: this._findMode
> +              findMode: this._findMode,
> +              openAndFocused: !this.hidden && document.activeElement == this._findField.inputField,
> +              quickFindTimeout: !!this._quickFindTimeout,

nit: can you change these names to have it indicate it's a boolean flag? Something like 'isOpenAndFocused' and 'isInQuickFindTimeout', perhaps...
Attachment #8963339 - Flags: review?(mdeboer) → review+
(Assignee)

Comment 8

4 months ago
Just for posterity (it can be hard to find old trypushes off mozreview once there's new ones), https://treeherder.mozilla.org/#/jobs?repo=try&revision=43d9b194b4148693ac40856d43566fe29f032567 had mochitest-plain orange in dom/html/test/forms/test_input_time_key_events.html that I can't reproduce.

I rebased and did a non-artifact repush, which hopefully resolves this?

https://treeherder.mozilla.org/#/jobs?repo=try&revision=8c5279a77b8302f84059772a3f3df7584b5276e3

Not really sure how/why these changes would impact the <input type=time> tests.
(Assignee)

Updated

4 months ago
Depends on: 1450219
Comment hidden (mozreview-request)
(Assignee)

Comment 10

4 months ago
OK, figured out the <input type=time> test, and updated for review comments, but it now seems that the browser_findbar test times out on win10 only... which is odd because I'm writing this comment on win10 and it passes locally for me. When I updated the test on my mac originally, I also tweaked it until it passed --verify . So not sure what's up. Maybe the infra machine is just slow, it's hard to tell. I'll investigate some more, maybe today maybe after the (long) weekend.
Comment hidden (mozreview-request)
(Assignee)

Comment 12

4 months ago
Rookie mistake, seems like initialProcessData won't get updated if processes have already started. So if the test runs against a child process that got initialized prior to tabbrowser's init() method (which is called onDOMContentLoaded in browser.xul), it has no shortcut data, so it doesn't send up keypresses, so the test fails.

Fixed by also adding a process message to send the data across to existing process(es).
Comment hidden (mozreview-request)
(Assignee)

Updated

4 months ago
Depends on: 1450247
Comment hidden (mozreview-request)

Comment 16

4 months ago
Pushed by gijskruitbosch@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/cbf007a7027f
remove find bar sync ipc message, r=mikedeboer
(Assignee)

Comment 18

4 months ago
Ugh. Amazing. Green on try ( https://treeherder.mozilla.org/#/jobs?repo=try&revision=c50be4d51697c66350f208571cd2a80a9855dce6 ) , and green with --verify on my Windows and mac machines, but hey-ho...
(Assignee)

Comment 19

4 months ago
So, something bizarre is happening when this fails on Linux.

The relevant test code is:

    /* some code that opens + focuses the find bar asynchronously */
    // send these keys with the content focused, so these forward to the content and it has to send them back:
    EventUtils.synthesizeKey("a");
    EventUtils.synthesizeKey("b");
    EventUtils.synthesizeKey("c");
    /* then check that all the keys arrive in the find bar correctly */


The normal way this works is:
1. the find bar starts opening. When the kid hears about the key event that triggers this (via normal key event forwarding), it starts listening for keypresses
2. we send keypresses. The kid forwards this to the parent to use (via sendAsyncMessage).
3. the find bar focuses and sends a message to the child to stop tracking keypresses (via sendAsyncMessage).
4. the kid stops sending keypresses and the test passes.

When the test fails, all the parent-side things still happen in the correct order (verified with logging). Yet somehow, in the child, what happens is:

1. get key event that triggers find bar opening + listening for keypresses
2. 1 or 2 keypresses arrive
3. the sendAsyncMessage arrives that tells us to stop listening for keypresses.
4. the last 1-2 keypresses arrive, but we don't forward them because of (3).

So the test fails.

I don't understand how this is possible. My understanding is that message ordering is guaranteed to be consistent for frame message managers (ie if you send A before B on the parent, A arrives in the child before B, too). Assuming that's right, I can only conclude the keypresses are somehow using a different queue / messaging system, or something. Assuming that's right, how can I guarantee ordering? Olli, can you help me understand what's happening?
Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(bugs)
There is no separate queue, unless there is some event suppression happening.

But when does find bar get focus? and when does it actually inform child side about it getting focus?
This smells like something being async in some cases and some cases sync.
Flags: needinfo?(bugs)
(Assignee)

Comment 21

4 months ago
(In reply to Olli Pettay [:smaug] (only webcomponents and event handling reviews, please) from comment #20)
> There is no separate queue, unless there is some event suppression happening.

Can you elaborate on what you mean by "event suppression" in this context?

> But when does find bar get focus? and when does it actually inform child
> side about it getting focus?
> This smells like something being async in some cases and some cases sync.

Based on logging with `Cu.reportError`, the find bar gets focus *after* the keypresses are sent to the child (so the ordering is correct in the parent). The findbar has a "focus" event handler and that synchronously calls `sendAsyncMessage` to tell the child the find bar now has focus. I don't think there's a discrepancy between async/sync in the find bar code. I don't know about event handling...

So to be clear, browser-content.js gets the key events (including the one that opens the find bar) using normal event listeners, not via message passing. It gets the focus event information via sendAsyncMessage. Somehow, in some cases the ordering of the events vs. messages are different between the parent and the child.
Flags: needinfo?(bugs)
(In reply to :Gijs (he/him) from comment #21)
> (In reply to Olli Pettay [:smaug] (only webcomponents and event handling
> reviews, please) from comment #20)
> > There is no separate queue, unless there is some event suppression happening.
> 
> Can you elaborate on what you mean by "event suppression" in this context?
When for example sync XHR spins event loop, we suppress user input events, and queue some of them to be fired later.
IIRC devtools use event suppression too.

> So to be clear, browser-content.js gets the key events (including the one
> that opens the find bar) using normal event listeners, not via message
> passing. It gets the focus event information via sendAsyncMessage. Somehow,
> in some cases the ordering of the events vs. messages are different between
> the parent and the child.
Are the key listener added to capturing phase of default group? If not, does something possibly spin the event loop before the listener is called?
Flags: needinfo?(bugs)
(Assignee)

Comment 23

4 months ago
(In reply to Olli Pettay [:smaug] (only webcomponents and event handling reviews, please) from comment #22)
> (In reply to :Gijs (he/him) from comment #21)
> > So to be clear, browser-content.js gets the key events (including the one
> > that opens the find bar) using normal event listeners, not via message
> > passing. It gets the focus event information via sendAsyncMessage. Somehow,
> > in some cases the ordering of the events vs. messages are different between
> > the parent and the child.
> Are the key listener added to capturing phase of default group? If not, does
> something possibly spin the event loop before the listener is called?

Olli and I discussed this on IRC. The listeners are in the bubbling phase and system group, in the child. As for the event loop spinning, nothing in the test does this nor does anything in the findbar implementation. Obviously I don't know if anything else in the browser spins the loop while the test is running. The JS stacks don't show evidence of this happening. I'd been using artifact builds to reproduce and test this stuff, so no C++ stacks. Olli couldn't think of other reasons 

I tried to get C++ stacks (to exclude the event loop spinning) by doing a full build in my VM. Due to this being a VM and me not having built in it for a year, and it being Ubuntu LTS, it basically took me all day to get it set up so I could get a build, and then it turned out that the result doesn't reproduce the issue that happens on try / artifact builds (not even with rr + chaos mode, or running the test in --verify mode - plenty of other unrelated timeouts in the mochitest framework, marionette, and earlier tests in that file that I'm not touching when running with rr, though...).

I will see tomorrow if I can reproduce again with artifact builds, and then try with artifact builds + gdb + the symbol server. I don't have very high hopes, but I don't see better options at this point.

Given that I haven't been able to reproduce this on non-Linux, if I can't dig into this with the setup described above, I'll probably put a bodge in the test that accepts only 1 or 2 of the keys making it on Linux, and file a follow-up with as much detail as I have. TBH, I don't think this is going to be a problem in practice (good luck dispatching multiple keys synchronously as a user while racing with focus), and Linux is such a tiny fraction of our userbase that it just doesn't really seem worth obsessing over until/unless we see problems with more reliable STRs and/or a more obvious way of fixing them.
(Assignee)

Comment 24

4 months ago
Additional options I just figured out thanks to bholley on IRC: try to do trypushes to get the C++ stacks, using something like nsTraceRefcnt::WalkTheStack(stderr) to get it to log stacks without having a debugger there...
(Assignee)

Comment 25

4 months ago
So after rebasing, the trypush with diagnostic logging was extremely green...

https://treeherder.mozilla.org/#/jobs?repo=try&revision=166120adf980d19fd5a1d51ea8008bbb7920e9d1

so I repushed a plain rebased trypush, which is also looking to be completely green:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=71571e89d8460da751a10c4a23d4918c5c0cedfb&selectedJob=172212809

So, uh, I guess the issue went away, and I'll just land this? :-\
Comment hidden (mozreview-request)

Comment 27

4 months ago
Pushed by gijskruitbosch@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/aaa0f152e8a3
remove find bar sync ipc message, r=mikedeboer

Comment 28

4 months ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/aaa0f152e8a3
Status: ASSIGNED → RESOLVED
Last Resolved: 4 months ago
status-firefox61: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
(Assignee)

Updated

3 months ago
Blocks: 1453421
You need to log in before you can comment on or make changes to this bug.