1187878 - SMS takes 5+secs to paint after device was locked then unlocked

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::SMS, defect)

Description

[:gerard-majax]

This is a recent regression. Master from around july 6th was NOT reproducint this for sure. I'd bet on something that has regressed recently, on a timescale of days.

STR:
 0. Have a big SMS thread (mine is 40000+ messages). I could reproduce on smaller threads but it was much less obvious
 1. Open the thread in SMS app
 2. Lock the device
 3. Unlock

Expected:
 SMS app should be repainted almost instantly, no text input visible at the bottom

Actual:
 It takes 5+ secs to repaint and show the text input at the bottom

This is reproduced fairly constantly on Z3 Compact device (dogfooding since march).

Comment 1

[Julien Wajsberg [:julienw]]

QA, can you try to find a build where we don't see this, and then try to bisect ?

Comment 2

[mac]

I can confirm the issue. 

Found on:

TCT Flame (got from Foxtrot Programme)
B2G version: 2.5.0.0-prerelease master
Platform version: 42.0a1
Build Identifier: 20150728030208
Firmware: v18D_nightly_v3
Git commit info: 2015-07-27 16:43:18 14e32276

This is first build on which it occurred.

Comment 3

[Pi Wei Cheng [:piwei] (inactive)]

QA trying to reproduce the issue here. I can't make reference workload to generate anything more than 2000. Can anyone enlighten me on how to make 40000 sms messages without it giving me an error?

Also,
> Expected:
> SMS app should be repainted almost instantly, no text input visible at the bottom

Is 'text input' referring to the blank space where you tap on it and it brings up the keyboard? Or is it referring to keyboard being invoked at the bottom? The first instance seems like expected behavior to me.

Comment 4

[:gerard-majax]

(In reply to Pi Wei Cheng [:piwei] from comment #3)
> QA trying to reproduce the issue here. I can't make reference workload to
> generate anything more than 2000. Can anyone enlighten me on how to make
> 40000 sms messages without it giving me an error?

Dogfood since day -1.

> 
> Also,
> > Expected:
> > SMS app should be repainted almost instantly, no text input visible at the bottom
> 
> Is 'text input' referring to the blank space where you tap on it and it
> brings up the keyboard? Or is it referring to keyboard being invoked at the
> bottom? The first instance seems like expected behavior to me.

That's the white input blank space. But it's the whole app that is frozen: no notification removed etc. Julien reproduced it on Flame with a light thread ...

Comment 5

[Pi Wei Cheng [:piwei] (inactive)]

I wasn't able to repro it on Flame with x-heavy (2000 sms). I'll keep trying.

Comment 6

[Pi Wei Cheng [:piwei] (inactive)]

I made a video, please look at it and determine whether this is reproducing the bug.

https://www.youtube.com/watch?v=B3h3iAbAJfw

Basically I need to scroll the thread after unlocking to see the thread not rendering for several seconds - is this considered reproducing the bug?

Device: Aries (RC4 > OTA'ed to dogfood-latest)
BuildID: 20150731163020
Gaia: 8502d07cd7e68da79303471acf64eea48b3dce24
Gecko: ca53d4297f02
Gonk: 2916e2368074b5383c80bf5a0fba3fc83ba310bd
Version: 42.0a1 (2.5 Master) 
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:42.0) Gecko/42.0 Firefox/42.0

Comment 7

[:gerard-majax]

It looks like you reproduce. Would have been easier if you followed the STR and tried to focus in the text input: in my case it was disappearing because I was actually sending messages. So app resized.

Comment 8

[Pi Wei Cheng [:piwei] (inactive)]

Thanks. Confirmed regression from Flame 2.2. Working on getting the window on Flame using 512MB memory (with 319MB it simply LMK's the SMS app after locking/unlocking).

Comment 9

[Pi Wei Cheng [:piwei] (inactive)]

b2g-inbound regression window:

Last Working
Device: Flame
BuildID: 20150724165247
Gaia: 31ade93da3e68f5e62f79bdf509ad20001a1a3e4
Gecko: 20bdf1cde964
Version: 42.0a1 (2.5 Master) 
Firmware Version: v18Dv4
User Agent: Mozilla/5.0 (Mobile; rv:42.0) Gecko/42.0 Firefox/42.0

First Broken
Device: Flame
BuildID: 20150724174446
Gaia: 0d8209e34ab98ef5ce7bead7cf26260017eb1e33
Gecko: dfb8020fb9cc
Version: 42.0a1 (2.5 Master) 
Firmware Version: v18Dv4
User Agent: Mozilla/5.0 (Mobile; rv:42.0) Gecko/42.0 Firefox/42.0

Last Working Gaia First Broken Gecko - no repro
Gaia: 31ade93da3e68f5e62f79bdf509ad20001a1a3e4
Gecko: dfb8020fb9cc

Last Working Gecko First Broken Gaia - repro
Gaia: 0d8209e34ab98ef5ce7bead7cf26260017eb1e33
Gecko: 20bdf1cde964

Gaia pushlog:
https://github.com/mozilla-b2g/gaia/compare/31ade93da3e68f5e62f79bdf509ad20001a1a3e4...0d8209e34ab98ef5ce7bead7cf26260017eb1e33

Caused by changes made in Bug 1171206.

Comment 10

[Zibi Braniecki [:zbraniecki][:gandalf]]

taking it. It's ugly and it's my fault.

Comment 11

[GitHub Autolander Bot]

Attachment: [gaia] zbraniecki:1187878-cache-intl-formatters-in-sms > mozilla-b2g:master

Comment 12

[Zibi Braniecki [:zbraniecki][:gandalf]]

Comment on attachment 8642731 [details] [review]
[gaia] zbraniecki:1187878-cache-intl-formatters-in-sms > mozilla-b2g:master

Ok, the trick here is to cache the formatters for TimeHeader. There may be other cases where we may want to do this, but it seems that only this one is on the critical path.

I would say we should also revisit the second approach (with .l10n-contains.date) since it requires us to create formatter for each of those elements on each formatting. Maybe we should do something similar to this and cache it.

Anyway, this fixes the bug.

Comment 13

[Julien Wajsberg [:julienw]]

Comment on attachment 8642731 [details] [review]
[gaia] zbraniecki:1187878-cache-intl-formatters-in-sms > mozilla-b2g:master

r=me

This actually makes a huge difference.

But shouldn't the caching of Intl.DateTimeFormat be done in Gecko instead ? It seems to me Gecko has all the necessary information to cache it _and_ to reset it if necessary ? Should we file a separate bug ?

Comment 14

[Julien Wajsberg [:julienw]]

If you file a separate bug, can you add the bug # in a comment near the _getFormatter function ?

Comment 15

[:gerard-majax]

Is it possible that this is leaking and contributing to bug 1189004 ?

Comment 16

[Zibi Braniecki [:zbraniecki][:gandalf]]

I would be surprised, because one thing that the code I landed last weak *doesn't* do is caching/retaining ;)

> But shouldn't the caching of Intl.DateTimeFormat be done in Gecko instead ? It seems to me Gecko has all the necessary information to cache it _and_ to reset it if necessary ? Should we file a separate bug ?

I'm not sure if that's a proper approach. Intl formatters are supposed to be used to cache what otherwise would be just (new Date()).toLocaleString(); - I don't know if we should/want to cache them separately and I don't think other platforms do that.

If you feel we should give it a try, can you file a bug?

Comment 17

[Zibi Braniecki [:zbraniecki][:gandalf]]

Also, just wanted to add that we are actually doing the formatting here *twice* now, because we react to languagechange, and that also triggers timeformatchange which we react to.

It's not very costly with this patch, but in the future we may want to do something smart about "if language or timeformat change update datetimes, but not twice please".

Comment 18

[Zibi Braniecki [:zbraniecki][:gandalf]]

Julien, I asked Waldo about it. His response:

Waldo: I'm inclined to say the amount of info we'd have to memoize on, in order to cache formatter information, would be pretty burdensome on the implementation, and on users doing the sensible thing of asking for a single formatter and using it repeatedly
Waldo: 	we'd have to do some architecture gymnastics to cache anyway, if we wanted -- right now we hang the ICU formatter thingy off the formatter JS object; we'd have to add reference counting, a primary owner object, or some other ponderous system all to handle this
Waldo: not to mention, even if we *did* cache the ICU/i18n parts, you'd still have to allocate a new formatter JS object every time, (to some degree) new bound functions to format/compare on the formatter, and other stuff
Waldo: ICU is probably the lion's share of it, but the rest is a dumb thing to be allocating for no reason, and it couldn't be avoided with caching


So, maybe we'll want some sort of a Gaia Intl Helper that will cache in a Map with key options and reset on language/time and fire one event in place of two "mozondatetimechange" ?

Comment 19

[Zibi Braniecki [:zbraniecki][:gandalf]]

I created bug 1191011 for such helper.

Comment 20

[Zibi Braniecki [:zbraniecki][:gandalf]]

Commit: https://github.com/mozilla-b2g/gaia/commit/738910d6cf28e3eba8f880f186a3b84ea37a0298