Last Comment Bug 609528 - Waiting to figure out doubleclicks leads to significant input lag with mousedown events
: Waiting to figure out doubleclicks leads to significant input lag with moused...
Status: RESOLVED WONTFIX
:
Product: Fennec Graveyard
Classification: Graveyard
Component: General (show other bugs)
: Trunk
: All All
: -- normal (vote)
: ---
Assigned To: Alon Zakai (:azakai)
:
Mentors:
http://10k.aneventapart.com/Uploads/83/
Depends on: 544614
Blocks: 616308
  Show dependency treegraph
 
Reported: 2010-11-03 19:41 PDT by Chris Jones [:cjones] inactive; ni?/f?/r? if you need me
Modified: 2011-05-02 10:30 PDT (History)
8 users (show)
See Also:
QA Whiteboard:
Iteration: ---
Points: ---


Attachments

Description Chris Jones [:cjones] inactive; ni?/f?/r? if you need me 2010-11-03 19:41:52 PDT
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?) 2010-11-10 11:34:05 PST
Could this be related to bug 579488?
Comment 2 Mark Finkle (:mfinkle) (use needinfo?) 2010-11-10 11:34:33 PST
Maybe it isn't
Comment 3 Chris Jones [:cjones] inactive; ni?/f?/r? if you need me 2010-11-10 11:36:25 PST
Nope.
Comment 4 Doug Turner (:dougt) 2010-11-10 11:39:27 PST
alon, can you run your profile on this and see if you see anything interesting?
Comment 5 Alon Zakai (:azakai) 2010-11-10 17:18:26 PST
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) 2010-11-10 17:29:04 PST
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?) 2010-11-10 18:16:54 PST
(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) 2010-11-10 20:04:11 PST
> 
> 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) 2010-11-12 10:19:00 PST
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) 2010-11-12 10:59:05 PST
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) 2010-11-12 11:20:13 PST
stechz made a useful tool for seeing events: http://people.mozilla.org/~bstover/recordevents.html
Comment 12 Benjamin Stover (:stechz) 2010-11-12 11:30:57 PST
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 2010-11-12 11:35:18 PST
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) 2010-11-12 11:39:19 PST
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) 2010-11-12 11:45:27 PST
> 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) 2010-11-15 10:00:16 PST
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 2010-11-15 11:17:49 PST
Or we could hack by immediately forwarding mousedown, but only delivering mouseup/click after the timeout.
Comment 18 Alon Zakai (:azakai) 2010-11-15 11:36:28 PST
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 2010-11-15 11:46:14 PST
Yes, it's a tradeoff.  We discussed this in #mobile last week.

Note You need to log in before you can comment on or make changes to this bug.