Closed Bug 1063708 Opened 10 years ago Closed 7 years ago

[meta] Unlocking the lockscreen takes over 1 CPU second

Categories

(Firefox OS Graveyard :: Gaia::System::Lockscreen, defect, P2)

All
Gonk (Firefox OS)
defect

Tracking

(tracking-b2g:backlog)

RESOLVED WONTFIX
tracking-b2g backlog

People

(Reporter: BenWa, Assigned: wcpan)

References

Details

(Keywords: perf, Whiteboard: [perf-wanted])

Unlocking the lockscreen takes over 1 second. A lot of this looks like we're just hitting some slow path we should be avoiding. Profile: http:://people.mozilla.org/~bgirard/cleopatra/#report=2a8074bc35a299d9ee08aa59dd1b9fe7734ef243&select=7673,8656
OS: Mac OS X → Gonk (Firefox OS)
Hardware: x86 → All
Depends on: 1063715
Depends on: 1063717
Can we get someone to look at these issues? The lockscreen could really be as simple as fading out an overlay. We should be able to get the unlock delay to 50ms or less, the frame rate up to 60 FPS and to nearly entirely eliminate the reflow, repaints that are occurring here.
Flags: needinfo?(21)
Tim, do you have someone responsible for the lockscreen that has some free time to look at that ?
Flags: needinfo?(21) → needinfo?(timdream)
While it's easy for my just to redirect the needinfo to :snowmantw, I don't think this bug has enough information for me or :snowmantw to work on. :BenWa would probably disagree (*everything* is shown in the profiling result in comment 1!), yet I would argue Gaia developers are not equip with the knowledge (at least, not yet) to understand these low level information. With that, I would have to cry for help. :sinker, is this something your team member can help my team with? We should be able to use this bug to start filling the gap...
Assignee: nobody → timdream
Flags: needinfo?(timdream) → needinfo?(tlee)
(In reply to Tim Guan-tin Chien [:timdream] (MoCo-TPE) (please ni?) from comment #4) > While it's easy for my just to redirect the needinfo to :snowmantw, I don't > think this bug has enough information for me or :snowmantw to work on. What information beyond the "unlock screen takes more than 1 second" and comparing that to the guidelines https://developer.mozilla.org/en-US/Apps/Build/Performance/Firefox_OS_app_responsiveness_guidelines do we need? > :BenWa would probably disagree (*everything* is shown in the profiling > result in comment 1!), yet I would argue Gaia developers are not equip with > the knowledge (at least, not yet) to understand these low level information. > That's a different topic then. I appreciate that you're asking for help from somebody that currently has these skills. We have run tutorials in the past on how to use the information from the profiler (I see the run attached above), and I know there is a number of people outside of Gecko that learned how to use this information and find the issues. It's a dangerous position to be in, to have a whole Gaia system team not be able to at least collect the data needed to diagnose performance issues, if not also diagnose the problems. We won't get anywhere if we have a large number of developers that just write the code not worrying about the performance, then ask a much smaller number of people to "make it fast".
Since samples are sparse, it is possible to have something busy on the background. Ting, could you take a look?
Flags: needinfo?(tlee) → needinfo?(tchou)
The delay seems from app switching. The lockscreen is actually an AppWindow, which when lockscreenslide-activate-right is triggered, it goes through application switching logic in AppWindowManager to get the homescreen to foreground, also the close() call in lwm_closeApp() to close lockscreen with fade out animation. If instant is true to set the overlay hidden in ls_unlock(), the screen goes to black right after sliding to right, and then after a short period the homescreen shows up.
Flags: needinfo?(tchou)
(In reply to Milan Sreckovic [:milan] from comment #5) > That's a different topic then. I appreciate that you're asking for help > from somebody that currently has these skills. We have run tutorials in the > past on how to use the information from the profiler (I see the run attached > above), and I know there is a number of people outside of Gecko that learned > how to use this information and find the issues. It's a dangerous position > to be in, to have a whole Gaia system team not be able to at least collect > the data needed to diagnose performance issues, if not also diagnose the > problems. We won't get anywhere if we have a large number of developers > that just write the code not worrying about the performance, then ask a much > smaller number of people to "make it fast". I understand. This is exactly what I have trying to fix for the past few days.
(In reply to Ting-Yu Chou [:ting] from comment #7) > The delay seems from app switching. It includes this sequential process in lwm_responseUnlock(): activeApp.ready(this.closeApp.bind(this)); which wait for next paint of homescreen and then close lockscreen with fade out animation, set lockscreen visibility false when animation end or time out. Kanru recommends using task tracer to understand how long do these two waitings take.
(In reply to Ting-Yu Chou [:ting] from comment #9) > activeApp.ready(this.closeApp.bind(this)); FWIW, I added some dump() with trunk code on Flame: 09-16 13:46:31.220 I/GeckoDump(10358): lwm_responseUnlock > ready 09-16 13:46:31.720 I/GeckoDump(10358): nextpaint is timeouted. 09-16 13:46:31.720 I/GeckoDump(10358): lwm_closeApp 09-16 13:46:32.160 I/GeckoDump(10358): atc_handleEvent _closingtimeout
I found that we are not taking screenshot for the foreground app when it is covered by lock screen. STR: Attach App Manager to System app, lock the screen, and probe AppWindowManager.getActiveApp()._screenshotOverlayState It will return "none" therefore we must wait for it to paint in the ready() function. Alive, what's the reason for not taking screenshot in this instance? (I do understand screenshot is a workaround and not the proper fix when dealing with Home screen app) (Note that we would still like to find out the timeline with task tracer)
Flags: needinfo?(alive)
FYI: the task tracer output http://people.mozilla.org/~kchen/isis/#bug-1063708-lockscreen.json Note the homescreen spent about 1s to repaint (taskid 46656229738599, 46656229738600, 46231027987798). The lockscreen waited 500ms then gave up and started animation (taskid 46231027987805).
(In reply to Kan-Ru Chen [:kanru] from comment #12) > FYI: the task tracer output > > http://people.mozilla.org/~kchen/isis/#bug-1063708-lockscreen.json > > Note the homescreen spent about 1s to repaint (taskid 46656229738599, > 46656229738600, 46231027987798). The lockscreen waited 500ms then gave up > and started animation (taskid 46231027987805). You could filter the tasks by source event type 1 and source event ID 46231027987798
(In reply to Tim Guan-tin Chien [:timdream] (MoCo-TPE) (please ni?) from comment #11) > I found that we are not taking screenshot for the foreground app when it is > covered by lock screen. > > STR: > > Attach App Manager to System app, lock the screen, and probe > > AppWindowManager.getActiveApp()._screenshotOverlayState > > It will return "none" therefore we must wait for it to paint in the ready() > function. > > Alive, what's the reason for not taking screenshot in this instance? > > (I do understand screenshot is a workaround and not the proper fix when > dealing with Home screen app) > > (Note that we would still like to find out the timeline with task tracer) For "why not take screenshot for homescreen" it was an old limitation that gecko cannot take PNG and you'd fixed it but we didn't catch up in gaia side to use the newest getScreenshot API.
Flags: needinfo?(alive)
Update on today's finding: The Task Tracer output in comment 13 confirmed majority of the time was spend on waiting for the foreground app to paint, which is exactly what being pointed out on comment 9. For complex app like home screen, the callback takes more than 1 sec to return, and we essentially give up and have our 500ms timer trigger the callback first. I believe getting rid of that timeout with some compromise in UX is doable for v2.1, so I have converted bug 1054904 for this purpose. Obviously that's not all the improvement we can do, so these two bugs are not dup to each other. I will post my proposal on getting rid of that wait-for-paint. Task Tracer also shows, compare to what :BenWa stated in his blog post [1] on the ideal situation: A) Even after the wait-for-paint, the main thread was blocked for sometime before the transition could begin. B) Main thread seems to be busy at something else when the compositor is working hard on animation. [1] http://benoitgirard.wordpress.com/2014/09/08/b2g-performance-polish-unlock-animation-part-2/ We can surely address that under this meta bug.
(In reply to Thinker Li [:sinker] from comment #6) > Since samples are sparse, it is possible to have something busy on the > background. Ting, could you take a look? The spare samples indicate that we're strongly starved for resources. Typically that's mean we don't have enough memory bandwidth, sometimes it means that we have too many tasks asking for a CPU slice. I've been looking at bug 1063717 where I was able to reduce the memory bandwidth and things speed up a measurable amount. If we can clear the bottleneck unrelated tasks will get faster here.
Let's take this to feature planning triage.
feature-b2g: --- → 2.2?
Per offline discussion with PM/EPM.
blocking-b2g: --- → backlog
feature-b2g: 2.2? → ---
tracking-b2g: --- → +
Unlock animation hits the fast path from bug 1098495.
Depends on: 1098495
blocking-b2g: backlog → ---
Enlisted in performance item. Make sure we have improvement here.
Blocks: 989590
Keywords: perf
Assignee: timdream → wpan
Whiteboard: [perf-wanted]
https://people.mozilla.org/~bgirard/cleopatra/#report=e0932877c711a552b9fddd0f799c08730d0e2ba8&filter=[{%22type%22%3A%22RangeSampleFilter%22,%22start%22%3A1369649,%22end%22%3A1370852}]&selection=0,1,7,61,62,7,63,64,74,6,7,130,131,132,168,7,119,120,176 lssm_transfer: 114ms lwm_handleEvent: 88ms lwm_publish: 62ms BaseModule.prototype.publish: 58ms _handle_hierarchychanged (@time_core.js): 55ms BaseIcon.prototype.start: 54ms TimeIcon.prototype._start: 34ms TimeIcon.prototype.update: 20ms aw_close: 16ms lswm_toggleLockedSetting: 9ms vm_handleEvent: 10ms FMDInit: 10ms onMutations (@l10n.js): 13ms PresShell::Flush (Flush_Style): 103ms RestyleTracker::ProcessRestyles: 97ms ElementRestyler::ComputeStyleChangeFor (Element: screen): 82ms BrowserElementParent.prototype._setupMessageListener: 23ms PresShell::Paint: 35ms atc_do_closing: 55ms lssss_transferTo: 18ms PresShell::Paint: 32ms this.InterAppCommService.receiveMessage: 15ms lssm_transfer has a very deep message passing path, so the time is sums up by many little actions. Restyling the whole screen is another hotspot, it has too many elements to calculate. I've tried to cache some unnecessary style calculations, like titlebar width, but it only reduces 20ms~30ms. Finally I tweaked the unlocking animation, let it instantly disapears so users will see the home screen right away. Although this does not decrease the processing time, but the visual effect is more responsive. The implementation is still a prototype, but Greg Weng and I think it's easier to change the UI animation, instead of refactoring the lock screen state manager or status bar/home screen layout. Rob MacDonald, Greg Weng and I had a short discussion about this approach, but we don't have a conclusion yet.
Depends on: 1199590
[Tracking Requested - why for this release]:
Priority: -- → P2
Firefox OS is not being worked on
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.