Closed Bug 827811 Opened 11 years ago Closed 10 years ago

Enter characters into text field within 140ms of touch end

Categories

(Firefox OS Graveyard :: Gaia::Keyboard, defect, P2)

Product:
Firefox OS Graveyard
Component:
Gaia::Keyboard
Platform:
ARM
Gonk (Firefox OS)
Type:
defect

Tracking

(blocking-basecamp:-, b2g18+)

Status:
RESOLVED FIXED
Project Flags:
blocking-basecamp -
Tracking Flags:
Tracking Status
b2g18 + ---

People

(Reporter: atsai, Unassigned)

References

Details

(Keywords: perf, Whiteboard: [c=effect p= s= u=], ux-tracking dupme)

Attachments

(2 files, 1 obsolete file)

Compressed Cleopatra-format profile of typing, before update #14 patch.
149.73 KB, application/octet-stream
Details
Compressed Cleopatra-format profile of typing, after update #14 patch.
120.21 KB, application/octet-stream
Details 
For now, if we press on the keyboard with two fingers the first one will not be sent.

STR:
1. Launch any app for typing, such as SMS, browser, or any other apps with textfields.
2. Click on a key ("s" is this example)
3. Click on any other key

Expected Result:
*. A result string start with "s"

Actual Result:
*. The "s" is not sent
blocking-basecamp: --- → ?
Blocks: 827813
Please note, this only happens if the keyboard automatically changes from upper to lower case. It works after the first letter until we choose upper case again. Would definitely block on this.
Sorry, meant to say I would definitely NOT BLOCK on this.
Wait, the key is entered into the textfield but only the highlighting is removed while it's still pressed.
Yes, both keys are entered in the order in which you lift your fingers. So if you are holding one key, then tap another, the character from the second key will be entered first. That's expected.

The highlighting problem has to do with the fact that they keys are replaced when we switch between caps/lower case. That's a trickier edge case to deal with. I wonder if a solution could be to never switch the keyboard layouts while a key is held.
Not holding the V1 for this. We would accept a patch.
blocking-basecamp: ? → -
tracking-b2g18: --- → +
Assignee: nobody → margaret.leibovic
On Android, when the user his a key that causes the layout to change, if another key was already being pressed, that first key gets entered, followed by the second key that's causing the keyboard to change. So, the user's first finger is still on the screen, but the touch is cancelled when the key is entered.

Also, when the user is touching one key, then taps a second key, the same thing happens and the first key is entered first. So it appears the general rule is keys aren't entered until a touchend happens, but that touchend will cause they keys from all active touches to be entered in the order they were touched.

I'm worried that it would be hard to make a low-risk patch for v1, so I'm unassinging myself to this for now.
Assignee: margaret.leibovic → nobody
QA Contact: wachen → whsu
From a new bug I filed on this issue earlier today (since closed as a dupe, upon rediscovering this bug):

> We have a serious issue to resolve with delays in typed characters appearing in text fields. The following video was shot on a high speed cam. In the "Stress Test" section you see the problem most clearly:

> https://www.dropbox.com/s/0785zq5ijfznug8/FFOS_KeyboardCompAnalysis_20130331.zip

> FFOS appears to stop printing selected characters in the text field until input activity has stopped and all previews have disappeared. This is easily encountered in day to day use when using two thumbs. The keyboard seems to lag causing the user slow down their text entry so the keyboard can catch up. This makes the keyboard feel slow and unpleasant. 

> Goal: Selected characters should appear (print?) in the text field within 100ms of a key touchend (?) event. Irrespective any other simultaneous keyboard activity (eg: key preview being visible, another key being pressed, etc).

Margaret, can you give that video a review and provide your take on the cause(s)? Switching to an Android-esque implementation would be fine, based on your description above. As would never switching to the lower-case layout (bug #810306 actually already makes this recommendation for aesthetic / usability reasons).
Flags: needinfo?(margaret.leibovic)
Summary: [Keyboard] multitouch event should be handled → Fix delays in entering characters to text field
Whiteboard: u=user c=keyboard s=ux-most-wanted
Average case analysis for Browser App with Keyboard App is as follows: (lets say for writing “Qualcomm” string)
 
1)      TouchDown to keyboard app’s highlight function call: ~8msec
2)      Keyboard app’s highlight function call to display Highlighted Keyboard Character is: ~121 ms (CSS ProcessRestyles() takes 3 ms + Another CSS ProcessRestyles() takes 1 ms+ PressShell::Paint() takes 84 ms)
3)      Keyboard app’s highlight function call to trigger key event ( handleUrlInputKeyPress() ) in browser app is :  ~116 ms (CSS ProcessRestyles() takes 3ms + PressShell::Paint() takes 84 ms)
4)      Browser App’s key event (handleUrlInputKeyPress() ) to Display character in search bar is : ~121 ms
 
So total time from touch down to display Character (1st paint event) in Browser Search Bar is : ~245ms ( Case 1 + Case 3 +Case 4)
The browser search bar is a really bad case for us because the browser is in-process due to an architectural restriction. Can you try any other app/field? Like the UI test app? Thanks.
Flags: needinfo?(tkundu)
84ms for the paint seems pretty lame. We should find out why thats so slow. Any takers?
Andreas, I spoke with Jed Davis about this yesterday. He's doing local profiling to confirm Tapas's findings since we don't have access to Qualcomm's profiling tool.
Assignee: nobody → jld
Jed,
Are you seeing the same timing as Tapas and have you been able to look deeper into the PressShell::Paint() call to see what most of the time there's being spent on?
Also, if anyone wants to profile the difference, I have a diff here with all of the gradients/pngs/rounded corners removed from the keyboard. It *feels* slightly more responsive, but I haven't gotten around to profiling it yet. Just doing this as UX said they would be open to simplifying the keyboard in case it meant for better responsiveness.

https://github.com/KevinGrandon/gaia/compare/master...bug_796408_keyboard_perf
What I'm seeing when typing in the URL bar (on unagi) is: on key down, 30ms handling the event, followed by 65ms repainting (mostly PresShell::Paint; a few samples in the compositor thread); on key up, 30ms handling the event, another 70ms repainting, 15ms in IndexedDB, ~7ms for reflow, and then two more calls to PresShell::Paint at 50ms each.

So that's about 100ms for the key-down and 225ms for the key-up.

Of the time in PresShell::Paint (averaged over the press/release pair I'm looking at), in chronological order: 18% in nsIFrame::BuildDisplayListForStackingContext, 8% in nsDisplayList::ComputeVisibilityForRoot, 36% in mozilla::FrameLayerBuilder::BuildContainerLayerFor, and 34% in mozilla::layers::BasicShadowLayerManager::EndTransaction.

Also we seem to be spending somewhere around 70ms repainting every time the cursor blinks.

It occurs to me to wonder about the CPU clock speed; judging by /proc/cpuinfo there's some kind of dynamic scaling going on, but I don't know the details, nor do I currently have data on how it changes during what I'm trying to profile.
(In reply to Andreas Gal :gal from comment #10)
> The browser search bar is a really bad case for us because the browser is
> in-process due to an architectural restriction. Can you try any other
> app/field? Like the UI test app? Thanks.

I tried typing in a text field in the UI tests app — we still spend 90% of our non-idle time in the b2g process rather than the "UI tests" process.
I've switched my gaia from v1-train to master to apply the patch in comment #14, and rebuilt my gecko from the latest b2g18, and that improves things; in particular, I don't see the multiple calls to PresShell::Paint I saw earlier.

I did some tests, averaging times over as many keypresses as I could type before the app needed to scroll sideways, and measuring the time spent in the main b2g process (== the keyboard app, here, I think):

Before: 165ms per press/release.
* 105ms in PresShell::Paint
** 50ms actually rendering
** 20ms building container layers from display lists
** 15ms building display lists
** 8ms computing visibility
* 37ms in nsBaseAppShell::OnProcessNextEvent
** 10ms in FindFrameTargetedByInputEvent (which seems to build a lot of display lists)
** 6ms handling deferred restyle/reflow
** 17ms actually dispatching the event
* 10ms on the compositor thread

After: 110ms per press/release.
* 54ms in PresShell::Paint
** 21ms actually rendering
** 18ms building container layers from display lists
** 10ms building display lists
** 3ms computing visibility
* 35ms in nsBaseAppShell::OnProcessNextEvent
** 10ms in FindFrameTargetedByInputEvent (which seems to build a lot of display lists)
** 6ms handling deferred restyle/reflow
** 17ms actually dispatching the event
* 10ms on the compositor thread

The UI Tests app consumes an additional 16-17 ms per keystroke in both cases.
A further observation: the compositor thread is woken up at least twice, and often only twice, per key release.  The first one follows activity in the UI Tests process, so I assume that it's displaying the character; the second one is after more activity in the b2g process (keyboard app), so I assume that it's clearing the pressed-key popup.  So, the time from when b2g wake up to the end of the second batch of compositor samples would be the time from keypress to displayed character.

That seems to be decreased from around 130-150 ms with the fancy keyboard to 95-100 ms with the comment #14 keyboard.

These are all smaller numbers than update #9 reports, but these are with gaia master, not v1-train.  Some comparison along those lines is in order, I think.
Sounds very promising, guys. Is it possible to see a screenshot of the stripped-down keyboard? Do we have any insight into what in particular might be introducing delays in the current KB design? eg: use of images, inefficient CSS selectors, etc.
Update bug title to capture 140ms target (which it sounds like we're achieving).
Summary: Fix delays in entering characters to text field → Enter characters into text field within 140ms of touch end
Have also filed bug #857907, which seems closely related, as they both hurt perceived performance.

> Rapid typing "clogs up" text entry, adding characters to input field in batches instead of individually
Today I learned that Cleopatra has built-in cloud sharing for profiles, which is more convenient than making people download and uncompress bug attachments.

Before: http://people.mozilla.com/~bgirard/cleopatra/#report=5ec1583fe16e12a60b3e2da49c4e3563a1d93e11
After: http://people.mozilla.com/~bgirard/cleopatra/#report=9fd579e2bffeb9f8568588ee6fd4a7005ed29342

Additionally, I'm not seeing a significant difference between gaia master and gaia v1-train (both with b2g18 gecko), to answer the last sentence of comment #18.
> Also, if anyone wants to profile the difference, I have a diff here with all
> of the gradients/pngs/rounded corners removed from the keyboard.

Kevin, thanks for the diff.

Jed,
Great work on the profiling and thanks for the updated profiles. Please capture and attach a screenshot of the stripped-down keyboard so Josh can see if it's good enough to ship.

> That seems to be decreased from around 130-150 ms with the fancy keyboard to
> 95-100 ms with the comment #14 keyboard.

Do you know how those css changes each contribute to the reduced time; e.g. which css rules are having the largest impact?

> Additionally, I'm not seeing a significant difference between gaia master
> and gaia v1-train (both with b2g18 gecko), to answer the last sentence of
> comment #18.

That's great news.
Attached image Stripped down keyboard (obsolete) — 
Here is the stripped down keyboard. We could obviously tweak it, but I'm not sure I would recommend implementing it yet. I think there might be other fixes we could investigate before having to take a hit on the visuals. I might have time to look into these next week.
(In reply to Michael Lee [:mlee] from comment #25)
> Do you know how those css changes each contribute to the reduced time; e.g.
> which css rules are having the largest impact?

I was looking into that, and discovered that deleting the line "background: url(images/key-shadow.png) no-repeat center -1px;" (without also doing... something, I'm not sure what, from the rest of the change) appears to provoke a rendering bug in Gecko.  Currently trying to track that down enough to file a meaningful bug....
(In reply to Jed Davis [:jld] from comment #27)
> (In reply to Michael Lee [:mlee] from comment #25)
> > Do you know how those css changes each contribute to the reduced time; e.g.
> > which css rules are having the largest impact?
> 
> I was looking into that, and discovered that deleting the line "background:
> url(images/key-shadow.png) no-repeat center -1px;" (without also doing...
> something, I'm not sure what, from the rest of the change) appears to
> provoke a rendering bug in Gecko.  Currently trying to track that down
> enough to file a meaningful bug....

May be related to bug #827813?
(In reply to Josh Carpenter [:jcarpenter] from comment #28)
> May be related to bug #827813?

It might be.  I've filed bug 858361, and I have a workaround.
I fixed bug 858454. That should eliminate:

35ms in nsBaseAppShell::OnProcessNextEvent or
17ms actually dispatching the event

or both from the profile, or well to be more precise it no longer happens synchronously. We will still churn that long but from the event loop and not within sendKey, which happens as part of endPress() and ontouchend.
Looking at the attached profiles it seems that with the styles enabled the painting operation is ~3 times more expensive than without (from ~48ms to 117ms,  check the nsDisplayList::PaintForFrame() operation). The breakdown of the additional time spent looks roughly like this:

- nsDisplayButtonBorderBackground::Paint() goes from 5ms to 33ms (!) with the background painting being the most expensive operation (2->25ms)

- nsDisplayBackgroundImage::Paint() which is not present when styling is disabled accounts for 14ms

- nsDisplayItem::RecomputeVisibility() goes from 7 to 22ms

- nsDisplayBorder::Paint() went from 2ms to 8ms

The rest seems to boil down to increased overhead costs in the very, very deep call chains. I think that it might be worth experimenting with the border and background styles to see if we can shave a few ms from the drawing operations.
As a side note I tried manually applying Andreas' patch to a mozilla-b2g18 source tree to do a quick v1-train test. Subjectively the keyboard seems more responsive, I can't notice any lag when pressing a key. On the other hand dragging the finger displays visible lag; I think we'll need to address the cost of the painting operation to get rid of that.
Thanks guys, great work. The UX team will discuss modifying layout to improve performance and follow up asap. In the interim I've filed bug #859189 ([Meta]Update keyboard layout) and made it a dependency of #835404 ([Meta]Improve keyboard performance)
(In reply to Andreas Gal :gal from comment #30)
> I fixed bug 858454. That should eliminate:
> 
> 35ms in nsBaseAppShell::OnProcessNextEvent or
> 17ms actually dispatching the event
> 
> or both from the profile, or well to be more precise it no longer happens
> synchronously. We will still churn that long but from the event loop and not
> within sendKey, which happens as part of endPress() and ontouchend.

This may actually be a regression.  Sort of.  Without that change, the key events are sent to the app inside the touch event handling, so the app can repaint itself in parallel with the keyboard repaint — for small values of "parallel", as this is on a single-core device, but the app typically has much less repainting to do than the keyboard (displaying a character vs. redrawing under the key popup) and finishes first.   After the change, sometimes, the callback to send the key events isn't run until after the timer that repaints the keyboard, which ties up the b2g process for 60ms.
What do you mean after the timer? We currently post an event to the event loop of the parent process, so the moment the keyboard JS is done it should be processed next. Nothing is on the itmer. Can you explain?
Flags: needinfo?(jld)
jld, can you try to change the settings in /sys/devices/system/cpu/cpu0/cpufreq and set scaling_min_freq to the value in scaling_max_freq? Does the time to paint change?
(In reply to Andreas Gal :gal from comment #35)
> What do you mean after the timer? We currently post an event to the event
> loop of the parent process, so the moment the keyboard JS is done it should
> be processed next. Nothing is on the itmer. Can you explain?

nsRefreshDriver uses an nsITimer; inside that timer callback, it calls nsViewManager::ProcessPendingUpdates, which repaints.
Flags: needinfo?(jld)
(In reply to Andreas Gal :gal from comment #36)
> jld, can you try to change the settings in
> /sys/devices/system/cpu/cpu0/cpufreq and set scaling_min_freq to the value
> in scaling_max_freq? Does the time to paint change?

For everyone who wasn't following the fun on IRC: we've determined that the kernel knows to raise the clock rate in response to touches, so this isn't an issue.
I have a few experimental removals from the keyboard CSS that I've been experimenting with: https://github.com/jld/gaia/compare/mozilla-b2g:v1-train...jld:keyboard-experiments

I'll get actual numbers on these tomorrow.
jld, please make sure to pick up the latest patch I landed on v1-train as well as the sendKey patch from mozilla-central. I re-profiled with those and the next biggest chunk of time now is spent painting backgrounds. I think we are rescaling the background of keys. ARM is known to be insanely slow scaling on the CPU. Can you see whether removing the background images makes a big difference? And if so, thats a really easy patch to uplift (e.g. we can make sure the background images have the right size, or remove them if UX approves).
comment 40: the css uses two of background-size: 100% 100%, which forces image scaling.
I also see 5% time spent in painting gradients, even after I remove said gradients in the css. Thats a little odd.
(In reply to Andreas Gal :gal from comment #40)
> jld, please make sure to pick up the latest patch I landed on v1-train as
> well as the sendKey patch from mozilla-central...Can you see whether removing the background images makes
> a big difference?

Jed,
Where are you with this issue? Did you followup on Andreas' suggestion and comment?
Flags: needinfo?(jld)
Whiteboard: u=user c=keyboard s=ux-most-wanted → c=performance
(In reply to Michael Lee [:mlee] from comment #43)
> (In reply to Andreas Gal :gal from comment #40)
[...]
> Jed,
> Where are you with this issue? Did you followup on Andreas' suggestion and
> comment?

To review: The sendKey patch seems to be a regression with respect to latency between touch end and text appearing in the app, and I filed bug 863671 — which, I notice, this bug is marked as depending on.  The other v1-train patches mentioned were to file off a few ms by avoiding forcing sync reflows by querying element positions from script (bug 858435), and I was already using those.

What remains is the suggestion to try removing images from the keyboard; that's been done several times. See bug 860318 in particular, and there's also somewhere that I did some science to determine the latency contributions of specific components of the current stylesheet.
Flags: needinfo?(jld)
(In reply to Jed Davis [:jld] from comment #44)
> and there's
> also somewhere that I did some science to determine the latency
> contributions of specific components of the current stylesheet.

You posted an analysis in comment 17 and I added some other information in comment 31 regarding the performance impact of disabling the styling. When I checked the most expensive operations seemed to be drawing the border's background and drawing the element's background. Maybe it would be worth to re-profile and see if things changed since then.
(In reply to Jed Davis [:jld] from comment #44)
> See bug 860318 in particular, and there's
> also somewhere that I did some science to determine the latency
> contributions of specific components of the current stylesheet.

Bug 860318 comment 1 is what I was thinking of.
Whiteboard: c=performance → c=performance, ux-tracking
I think this bug has been resolved by bug 860318; I'll profile with the updated keyboard CSS to verify.
Flags: needinfo?(tkundu)
Flags: needinfo?(margaret.leibovic)
Status: NEW → ASSIGNED
Keywords: perf
Whiteboard: c=performance, ux-tracking → c= , ux-tracking
We're not quite there yet.  Some keypresses are under and some aren't, and the difference seems to be whether the RefreshDriverTimer (in the main process) goes off once or twice during the touch end handling.  Here's a profile (unagi, master/mozilla-central):

https://people.mozilla.com/~bgirard/cleopatra/#report=1662797c4855035900801042ace7715e6591ef41

I think I'll see how this works with r127931:db5fe4e235ee backed out (see bug 863671) for comparison.
Bug 863671 seems to not make much difference now — possibly due to the keyboard repaint being fast enough to finish before the app's repaint, or something like that.  Here's a profile:

https://people.mozilla.com/~bgirard/cleopatra/#report=bdbb8d949776e6a58a415611f00800df230486e0

One thing I notice is that we're spending 30-35ms in a DOM Worker thread running the suggestion logic, which isn't exactly helping.  I think this isn't necessary for getting a letter painted in the app and could be deferred until after the other work, but the OS doesn't know that.
Assignee: jld → nobody
Attachment #733633 - Attachment is obsolete: true
Status: ASSIGNED → NEW
Priority: -- → P2
Whiteboard: c= , ux-tracking → [c=effect p= s= u=], ux-tracking
Since all dependent bugs have been resolved, QA please retest this.
Keywords: qawanted
QA Contact: whsu → ckreinbring
After testing on the Buri 1.2 commercial RIL, tapping two keys at once will highlight both until they're released.  Whichever key is released first is entered first.  

Build ID: 20131106004004
Gecko: http://hg.mozilla.org/releases/mozilla-b2g26_v1_2/rev/6a831fcb96f4
Gaia: 2140c987fdde1c99097018f7e93b0bbd43d2125d
Platform Version: 26.0
RIL Version: 01.01.00.019.281
Keywords: qawanted
FIXED per comment 51.
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Whiteboard: [c=effect p= s= u=], ux-tracking → [c=effect p= s= u=], ux-tracking dupme
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: