743736 - Touch event handlers on nytimes.com take a long time to run

Status: RESOLVED WORKSFORME

(Firefox for Android Graveyard :: General, defect)

Description

[Kartikaya Gupta (email:[e-mail])]

Attachment: Log of nsAppShell EVLOG prints

I'm seeing runtimes on the order of 23ms in nsAppShell.cpp to process touch events. I'm attaching a log of the nsAppShell output while doing a scroll on nytimes.com fully zoomed out on a GN. Event type 2 is the touch events, so look for the time spent between a line like

04-09 17:56:54.064 I/Gecko   ( 8228): nsAppShell: event 0x5f8de060 2

and the corresponding

04-09 17:56:54.072 I/Gecko   ( 8228): nsAppShell: -- done event 0x5f8de060 2

In this particular log the first one only takes ~8ms but the next few are at 31ms, 24ms, 23ms and 31ms.

Comment 1

[Kartikaya Gupta (email:[e-mail])]

I did a save-as on nytimes.com and grepped the various included scripts to see if i could figure out what's running, but unfortunately the script in question is obfuscted. here's a small snippet of the bottom.js file which i believe has the touch listener:

i=(/android/gi).test(navigator.appVersion),a=c||d||i,h=a?"touchstart":"mousedown",k=a?"touchmove":"mousemove",g=a?"touchend":"mouseup",j="translate"+(f?"3d(":"("),b=f?",0)":")",e=0;window.iScroll=l;})

it looks like some sort of CSS animation, based on the "translate" and other code in the surrounding area of where i found this.

Comment 2

[Jeff Muizelaar [:jrmuizel]]

It would be good to time these events in other browsers to see if we are doing much worse.

Comment 3

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

Brian - Can you try to see how other browsers work here? Do some timing, maybe using Chrome and the Chrome remote tools?

Comment 4

[Brian Nicholson (:bnicholson)]

Attachment: touch events test

While looking this, I discovered that the stock browser/Chrome do not send continuous touch events to the page unless the page calls preventDefault() in touchstart. I assume this is an optimization they're using for touch events.

Here's a test case - try dragging inside/outside the red square in each browser. In Fennec, you'll notice that logcat shows touchmove events when dragging outside of the square. The stock browser and Chrome, however, do not.

Comment 5

[Brian Nicholson (:bnicholson)]

Attachment: touchmove times (with coalescing)

I downloaded the page at nytimes.com so I could add event listeners that could be used by the different browsers. The page is available at http://people.mozilla.com/~bnicholson/nytimes/.

I included a custom script (http://people.mozilla.com/~bnicholson/nytimes/touchevents.js) that logs touchmove events for 5 seconds once a touchstart event is received. During this period, I continuously moved my finger on the page to trigger touchmove events.

I've attached the full log, but here's the summary:

                Stock   Chrome  Fennec
timespan (ms)   4945    4959    5095
#events         264     255     55
average (ms)    18.8    19.5    94.3

timespan is the difference between the last and first touchmove event (should be close to 5 seconds). #events is the number of events logged in that timespan. average represents the average delay between each touchmove event.

As you can see, we're considerably slower (~5x) than the other browsers.

I don't think this is related to the script kats mentioned in comment 1 (http://people.mozilla.com/~bnicholson/nytimes/bottom.js); that script seems to be just for the horizontal scroller at the bottom of the page.

Comment 6

[Wesley Johnston (:wesj)]

This doesn't really show what our average processing time is for these events. For instance, we coalesce touchmove events here:

http://mxr.mozilla.org/mozilla-central/source/widget/android/nsAppShell.cpp#616

which might distort these numbers (I'm not sure how we decide if we should coalesce or not, probably related to what else is in the queue?).

Comment 7

[Kartikaya Gupta (email:[e-mail])]

I agree with what wesj said. You can try disabling the coalescing code and seeing if that gives us different numbers. Just comment out that entire case statement and let the touch events get handled by the default clause.

Comment 8

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

Brian - can you talk to Wes about implementing the behavior in comment 4 ?

Comment 9

[Wesley Johnston (:wesj)]

FWIW, I don't think we should do that, especially without looking harder into what different browsers are doing across devices and OS's, or getting some good numbers here. I posted two alternative fixes in bug 745381 that should help things a lot.

Comment 10

[Brian Nicholson (:bnicholson)]

Attachment: touchmove times (no coalescing)

Here's an updated log after disabling event coalescing. The average delay between events dropped about 30% from the first log, so we're still quite slow compared to other browsers.

Without coalescing, we're getting events faster than we can handle them. If I drag my finger on the screen and release after a few seconds, I still see touch event messages being dumped to the log several seconds after my finger has been lifted. You can also see that we had a range of 7145ms between the first and last events - even though the timer is set to just 5000ms - so we are clearly being overworked.

Comment 11

[Brian Nicholson (:bnicholson)]

Attachment: touchmove times (no coalescing, with fixes)

With the fixes from bug 745381 and bug 745936, it looks like we are right on par with the stock browser and Google Chrome. Here's a summary (no coalescing):

		Stock		Chrome		Fennec
timespan (ms)	4945		4959		5008
#events		264		255		270
average (ms)	18.8		19.5		18.7

Comment 12

[Brian Nicholson (:bnicholson)]

(In reply to Wesley Johnston (:wesj) from comment #9)
> FWIW, I don't think we should do that, especially without looking harder
> into what different browsers are doing across devices and OS's, or getting
> some good numbers here. I posted two alternative fixes in bug 745381 that
> should help things a lot.

Interesting - this might actually just be a WebKit bug. The steps in comment 4 were reproducible on ICS, but when I tried it on GB, it showed touchmove events even without preventDefault().

There's a bug filed here:
http://code.google.com/p/android/issues/detail?id=19827

Comment 13

[Brian Nicholson (:bnicholson)]

Since bug 745381 and bug 745936 fixed the performance issue, and since it no longer looks like we should be implementing comment 4, resolving this as WFM.