609528 - Waiting to figure out doubleclicks leads to significant input lag with mousedown events

Status: RESOLVED WONTFIX

(Firefox for Android Graveyard :: General, defect)

Description

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

STR
 (1) Open URL
 (2) Start game
 (3) Tap inside the canvas to move the little "comet" thing around

A round-trip from tap to comet-moving seems to take upwards of a second or more at worst (on my galaxy s).  This seems way high; the framerate of the game looks fine, panning perf in chrome is OK, and an IPC round-trip from chrome->content->chrome should take in the neighborhood of 1ms in ideal circumstances.  I suspect there's an unexpected stall in that pipeline somewhere.

Filing in fennec but this might be a platform thing.

Comment 1

[Mark Finkle (:mfinkle) (use needinfo?)]

Could this be related to bug 579488?

Comment 2

[Mark Finkle (:mfinkle) (use needinfo?)]

Maybe it isn't

Comment 3

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Nope.

Comment 4

[Doug Turner (:dougt)]

alon, can you run your profile on this and see if you see anything interesting?

Comment 5

[Alon Zakai (:azakai)]

Profile looks like this:

                 PLayersChild|Msg_Update [SYNC/RPC]    total latency: 5.0624    total processing: 0.5379    total: 1648:1648:1648
         PBrowserParent|Msg_AsyncMessage               total latency: 3.6084    total processing: 0.6375    total: 114:114:114
     PBrowserParent|Msg_LoadRemoteScript               total latency: 1.2777    total processing: 0.0179    total: 7:7:7
             PBrowserParent|Msg_Activate               total latency: 1.0011    total processing: 0.0024    total: 49:49:49
      PLayersChild|Msg_PLayerConstructor               total latency: 0.5506    total processing: 0.0000    total: 5:0:5
                 PBrowserParent|Msg_Move               total latency: 0.3724    total processing: 0.0001    total: 2:2:2
         PBrowserChild|Msg_GetIMEEnabled [SYNC/RPC]    total latency: 0.2003    total processing: 0.0013    total: 48:48:48


More specifically and importantly, the problem seems to be that each click to move causes this (viewed from the parent side):

[time:1289437853812434][PBrowserParent] Sending Msg_Activate([TODO])

[time:0][InProcessParent] Send Msg_AsyncMessage(Browser:MouseDown)
[time:1289437853812721][PBrowserParent] Sending Msg_AsyncMessage([TODO])

[time:1289437853872203][PBrowserParent] Received Msg_AsyncMessage([TODO])
[time:0][PBrowserParent] RENAMEBrowser:ContextMenu Msg_AsyncMessage([TODO])
[time:1289437853872373][PBrowserParent] FinishedReceiving Msg_AsyncMessage([TODO])

[time:0][InProcessParent] Send Msg_AsyncMessage(Browser:MouseUp)
[time:1289437854307123][PBrowserParent] Sending Msg_AsyncMessage([TODO])

[time:1289437854322439][PBrowserParent] Received Msg_AsyncMessage([TODO])
[time:0][PBrowserParent] RENAMEFormAssist:Hide Msg_AsyncMessage([TODO])
[time:1289437854322640][PBrowserParent] FinishedReceiving Msg_AsyncMessage([TODO])

[time:1289437854322663][PBrowserParent] Received Msg_AsyncMessage([TODO])
[time:0][PBrowserParent] RENAMEFindAssist:Hide Msg_AsyncMessage([TODO])
[time:1289437854322721][PBrowserParent] FinishedReceiving Msg_AsyncMessage([TODO])

[time:1289437854322741][PBrowserParent] Received Msg_SetIMEEnabled([TODO])
[time:1289437854322762][PBrowserParent] FinishedReceiving Msg_SetIMEEnabled([TODO])

Comment 6

[Alon Zakai (:azakai)]

Forgot to say, spaces separate messages in the log above (each message can have more than 1 line).

So, we have (from the parent's perspective):

* Send Msg_Activate
* Send Browser:MouseDown
* Recv Browser:ContextMenu
* Send Browser:MouseUp
* Recv FormAssist:Hide
* Recv FindAssist:Hide
* Recv [Set|Get]IMEEnabled (GetIMEEnabled is sync!)

Basically, lots of frontend messages (but to be fair there are also 20/sec Layers_Update sync messages). Do we need all of these?

Comment 7

[Mark Finkle (:mfinkle) (use needinfo?)]

(In reply to comment #6)
> Forgot to say, spaces separate messages in the log above (each message can have
> more than 1 line).
> 
> So, we have (from the parent's perspective):
> 
> * Send Msg_Activate
> * Send Browser:MouseDown
> * Recv Browser:ContextMenu
> * Send Browser:MouseUp
> * Recv FormAssist:Hide
> * Recv FindAssist:Hide
> * Recv [Set|Get]IMEEnabled (GetIMEEnabled is sync!)
> 
> Basically, lots of frontend messages (but to be fair there are also 20/sec
> Layers_Update sync messages). Do we need all of these?

The Browser:ContextMenu message should only be sent if the tap was a long tap.

The FormAssist:Hide and FindAssist:Hide should really only be sent if we are displaying the FormUI or FindUI, but the UI is in chrome and the trigger to hide is in content, so it's hard to keep the state sync'ed.

We could consolidate the FormAssist:Hide and FindAssist:Hide into a single message, used to tell assistant UIs to hide.

----

Since these front-end messages are async, would they impact rendering the "dot" in a new location on the content display?

Comment 8

[Alon Zakai (:azakai)]

> 
> Since these front-end messages are async, would they impact rendering the "dot"
> in a new location on the content display?

As async they aren't too bad in themselves. I am concerned though about what is around them. For example, Browser:ContentMenu being sent means that each click currently runs this code: http://mxr.mozilla.org/mobile-browser/source/chrome/content/content.js#715 (which you say should only be run on long taps - I'll investigate why this happens).

Even as async messages, though, they can add to latency, when there are sync messages being passed, which there are here (since sync messages must wait their turn - we don't prioritize them).

Comment 9

[Alon Zakai (:azakai)]

Looks like this is an issue with mouse events. This is responsive in Firefox, but lags for about 1sec on Fennec,

  <body>
  waka
  <script>
    document.addEventListener('mousedown', function() {
      alert('mousedown!');
    }, false);
  </script>
  </body>

Comment 10

[Alon Zakai (:azakai)]

With stechz's help, the problem turns out to be that we wait to figure out if something is a doubleclick or not. That delay, kDoubleClickInterval = 400ms, is the source of lag here. Remove the delay, and it goes away.

So this is a frontend issue with input handling. stechz and I can't think of a simple solution that wouldn't break stuff.

For this specific game, perhaps it would be fixed if we supported tapdown events (that might be how the native android browser runs the game well). But it would be good to figure out a way to fix the input lag here.

Comment 11

[Alon Zakai (:azakai)]

stechz made a useful tool for seeing events: http://people.mozilla.org/~bstover/recordevents.html

Comment 12

[Benjamin Stover (:stechz)]

Stock browser does no better than us, at least on my N1. My theory is that the game sniffs for webkit and listens for webkit-specific touch events.

If we want interactive content at all on mobile, we really want multitouch events (bug 544614).

Comment 13

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

It doesn't sniff for webkit, it just registers to listen to touch events

var L=function(N,M,O){document.addEventListener(N,M,O)};L("mousemove",c,false);L("mousedown",l,false);L("mouseup",I,false);h.addEventListener("touchstart",i,false);L("touchmove",q,false);L("touchend",v,false);

Comment 14

[Alon Zakai (:azakai)]

Isn't the real problem though that we mix regular and 'meta' input here, that is, that a click can be either to control the browser (doubleclick to zoom) or to control the web page (click)?

If we didn't zoom on doubleclick, couldn't we just do input handling like desktop Firefox does, and not suffer any lag?

Or is zooming on doubleclick not negotiable?

Comment 15

[Benjamin Stover (:stechz)]

> If we didn't zoom on doubleclick, couldn't we just do input handling like
> desktop Firefox does, and not suffer any lag?
> 
> Or is zooming on doubleclick not negotiable?

I think there is no way that we'll change doubletap behavior.

Comment 16

[Alon Zakai (:azakai)]

Without changing doubletab behavior, the only possible way to improve this game's input lag would be to implement |touch| events (bug 544614).

Comment 17

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Or we could hack by immediately forwarding mousedown, but only delivering mouseup/click after the timeout.

Comment 18

[Alon Zakai (:azakai)]

Do you mean to forward mousedown to web pages immediately? If so then the problem is there should be no mousedown if it is actually part of a doubleclick - that's input for the browser, not the web page. Sending unneeded mousedowns might break some web pages.

Comment 19

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Yes, it's a tradeoff.  We discussed this in #mobile last week.