1076327 - Home screen does not appear

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::System::Window Mgmt, defect, P1)

Description

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: logcat logs

STR:
1) Run some stability test and reboot randomly
2) Homescreen does not show icons after rebooting.


I can reproduce this issue very easily in my local device. if you give us some logging patch then I will quickly verify and update you.


Affected Device screenshot is same as https://bug1048639.bugzilla.mozilla.org/attachment.cgi?id=8476084

Comment 1

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

[Blocking Requested - why for this release]:

Comment 2

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

adb shell b2g-info
                          |     megabytes     |
           NAME  PID PPID CPU(s) NICE  USS  PSS  RSS SWAP VSIZE OOM_ADJ USER    
            b2g  210    1   27.4    0 65.0 73.0 91.8  0.0 260.7       0 root    
         (Nuwa)  614  210    0.8    0  2.6  5.3 14.0  0.0  54.1     -16 root    
     Homescreen 1136  614    5.7   18 20.7 25.1 37.3  0.0  99.8       8 u0_a1136
Built-in Keyboa 1382  210    1.3   18 12.4 17.3 29.9  0.0  80.0      10 u0_a1382
(Preallocated a 1489  614    0.5   18  5.7  8.9 19.2  0.0  60.9       1 u0_a1489


We are seeing that homescreen is in background although we are pressing home key. Any ideas on it ?

Comment 3

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Can anyone tell me what is causing "Find my device" app to run during boot ?

Comment 4

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: memory-reports.tar.bz2

GC/CC logs from affected device . @kyle could you please check why homescreen has OOM_ADJ=8 (background app) here ? Homescreen must have OOM_ADJ=2 as it is only foreground app in affected device.

Comment 5

[Kevin Grandon :kgrandon]

Doing a needinfo on FMD peers/owners. Hey guys - we would like to rule out that FMD is not causing any problems that we are seeing here. Could you help us out with some information:

1 - Why and when does FMD start during boot of the device.
2 - Do you think it could be causing any window management issues and the home screen not to display?
3 - Are there any patches that we could implement to debug FMD if it should not be starting, or disable it completely and check if this issue persists.

Comment 6

[Guilherme Gonçalves [:ggp]]

Hi Kevin,

Here are my answers. I'm also keeping the ni? to Jared as he's been more involved in FMD than me
lately, so he may be able to correct me if my memory fails.

(In reply to Kevin Grandon :kgrandon from comment #5)
> 1 - Why and when does FMD start during boot of the device.

There are quite a few circumstances that cause FMD to start, but if you're seeing the app
being launched on a device without ever enabling FMD, then it's most likely due to the screen
being unlocked. We launch the app when the screen is unlocked even when FMD is disabled
(bug 1062558).

Other situations in which FMD may be launched include: alarms that were set by the app
in the background, geolocation being enabled/disabled, and login/logout of Firefox Accounts.
Having a log with Gaia debug traces will help determine why it's being launched if you need
to know.

> 2 - Do you think it could be causing any window management issues and the
> home screen not to display?

Not that I can think of.

> 3 - Are there any patches that we could implement to debug FMD if it should
> not be starting, or disable it completely and check if this issue persists.

Enabling Gaia debug traces logs a lot of useful information when debugging FMD.

Sadly we don't have any easy provisions for disabling FMD entirely, but if reflashing is an
option, I believe removing/commenting out apps/findmydevice/js/findmydevice_launcher.js
should mostly do the trick -- FMD can also be launched from the Settings app, but that will
never happen without user interaction. Let me know if you need any help with this.

Comment 7

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

(In reply to Guilherme Gonçalves [:ggp] from comment #6)

> Enabling Gaia debug traces logs a lot of useful information when debugging
> FMD.
> 

Could you please point me to exact steps for it ?

> Sadly we don't have any easy provisions for disabling FMD entirely, but if
> reflashing is an
> option, I believe removing/commenting out
> apps/findmydevice/js/findmydevice_launcher.js
> should mostly do the trick -- FMD can also be launched from the Settings
> app, but that will
> never happen without user interaction. Let me know if you need any help with
> this.

Thanks for nice tip. I will do it TEMPORARILY to see if this solves this bug or not.

Comment 8

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

I am putting NI on you for gaia debug traces in Comment 7 :) thanks for your help

Comment 9

[Jared Hirsch [:jhirsch] (he/him) (Needinfo please)]

Thanks for the detailed response, ggp! I think you've covered all the cases in which FMD would start up.

(In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from comment #8)
> I am putting NI on you for gaia debug traces in Comment 7 :) thanks for your
> help

To enable gaia debug traces, go to Settings > Developer Menu, then check the Gaia Debug Traces checkbox. The additional output will then appear in `adb logcat` output.

Comment 10

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

I got a fix from alive in https://github.com/mozilla-b2g/gaia/pull/24687 . I am still testing it. I will update shortly.

Comment 11

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: logcat_homescreen_good.txt

Hi alive,

I verified and confirmed that we are not seeing this issue any more after applying FIX from [1] https://github.com/mozilla-b2g/gaia/pull/24687


here is the logcat for testcase when we see this issue does not come at all.

Comment 12

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: logcat_homescreen_noicon_withadditionallogs.txt

Hi Alive,

I also reproduced this issue and collected additional logs by applying ONLY LOGGING PATCH [1] https://github.com/mozilla-b2g/gaia/pull/24697/commits

This confirmed me that Comment 11 has a real fix for this RACE issue during startup. Could you please do following steps : 

1) Upload fix for this issue 
2) Enable dynamic logging for detecting these kind of window transition bugs (including bug 1070431). This dynamic logging will really cut off lots of debugging and testing effort in these type of issues. 

Thanks a lot for your help :)

Comment 13

[(inactive after 6/18) Alive Kuo [:alive]]

Comment on attachment 8499177 [details]
logcat_homescreen_noicon_withadditionallogs.txt

Log analysis:
* Homescreen is displayed by certain event(need further logging) before ftuskip is fired.
* AppWindowManager opens the homescreenWindow correctly; however, it seems the homescreenrequestforeground event is either
** Not dispatched to VisibilityManager so nobody permits its foreground request
** VisibilityManager thinks now device is still locked so it does not guarantee the request.
* When next time homescreen displayed by ftuskip event, active app of AppWindowManager is already the homescreen so it early returns in the display() function()

Comment 14

[(inactive after 6/18) Alive Kuo [:alive]]

Attachment: Logging patch 2

Hey, here is another logging only patch. I want to bother you for more logging, please help!

Comment 15

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: logcat_bad.txt

(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #14)
> Created attachment 8499325 [details]
> Logging patch 2
> 
> Hey, here is another logging only patch. I want to bother you for more
> logging, please help!

here is the logcat log for ONLY above logging patch (attachment 8499325 [details]).

Comment 16

[howie [:howie]]

Triage: blocking.

Comment 17

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from comment #15)
> Created attachment 8499391 [details]
> logcat_bad.txt
> 
> (In reply to Alive Kuo [:alive][NEEDINFO!] from comment #14)
> > Created attachment 8499325 [details]
> > Logging patch 2
> > 
> > Hey, here is another logging only patch. I want to bother you for more
> > logging, please help!
> 
> here is the logcat log for ONLY above logging patch (attachment 8499325 [details]
> [details]).

Here is my analysis:
* When system is booted, lockscreen settings is by default true and lockscreen window is not instantiated. [1]
* The tester press power button repeatedly during booting, hence triggering the lockscreenWindow to be opened [2] hence system.locked is true at this timing.
* Homescreen is launched by showwindow event [3]
* Homescreen will ask to be foreground to VisibilityManager, but at this timing, System.locked is still true. It's only changed to false after LockscreenWindowManager set it in lockscreen-request-unlock handler.[4]
* Since system is still locked, the foreground request will ignored. [5]
* System.locked will be set to false once the accidently opened lockscreen window to close by lockscreen-request-unlock
* After ftuskip event really happens, activeApp of appWindowManager is already homescreen so AWM just do nothing here. [6][7]

[1] https://github.com/mozilla-b2g/gaia/blob/v2.1/apps/system/js/lockscreen_window_manager.js#L38
[2] https://github.com/mozilla-b2g/gaia/blob/v2.1/apps/system/js/lockscreen_window_manager.js#L134
[3] https://github.com/mozilla-b2g/gaia/blob/v2.1/apps/system/js/app_window_manager.js#L800
[4] https://github.com/mozilla-b2g/gaia/blob/v2.1/apps/system/js/lockscreen_window_manager.js#L244
[5] https://github.com/mozilla-b2g/gaia/blob/v2.1/apps/system/js/visibility_manager.js#L67
[6] https://github.com/mozilla-b2g/gaia/blob/v2.1/apps/system/js/app_window_manager.js#L432
[7] https://github.com/mozilla-b2g/gaia/blob/v2.1/apps/system/js/app_window_manager.js#L128

Conclusion:
This is a sad result of several asynchronous states; there are also some minor issues but get together to affect this result:
* Do we really need to treat System.locked is the as same as only opened state of lockscreen window?
* Do we really need to launch homescreen on request-unlock event?
* Do we really need to skip second displayapp request if the app is already opened?

The long term solution is having a bootloader to deal with FtuLauncher + LockscreenWindowManager + HomescreenLauncher race because they all need to check settingsDB before going to ready state.

The short term solution might be to fix one of the questions listed above due to a blocker.

Comment 18

[(inactive after 6/18) Alive Kuo [:alive]]

Attachment: fix+log for v2.1

Tapas, here I am trying to fix it in another way. Please feedback if it's still reproducible. If yes please give me the log. Otherwise we could start the review.

Comment 19

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: logcat_good.txt

(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #18)
> Created attachment 8499477 [details] [review]
> fix+log for v2.1
> 
> Tapas, here I am trying to fix it in another way. Please feedback if it's
> still reproducible. If yes please give me the log. Otherwise we could start
> the review.


I don't see this issue with this patch. I also attached logcat logs for it.

Comment 20

[(inactive after 6/18) Alive Kuo [:alive]]

Attachment: patch for master

Analysis is in comment 17.

Comment 21

[Ken Chang[:kenkai]]

Tim, it is great if we can have your review. Thanks.

Comment 22

[(inactive after 6/18) Alive Kuo [:alive]]

tbpl seems in a bad state now; leave open until it back and the test passes.

Comment 23

[(inactive after 6/18) Alive Kuo [:alive]]

Well, I am blocked by a test which is successful but failed on tbpl.
https://treeherder.mozilla.org/ui/#/jobs?repo=gaia-try&revision=12f7069856f1

Not sure what's wrong, but according to the VERY slow progress of running Gij in tbpl this patch will not be landed today.

Comment 24

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #23)
> Well, I am blocked by a test which is successful but failed on tbpl.
Successful at local running I mean.

Comment 25

[(inactive after 6/18) Alive Kuo [:alive]]

Without any change: bookmark_web_result_test.js is failing
Change to appWindowManager: lockscreen_media_playback + bookmark_web_result is failing

The screenshot shows no homescreen and the error message is timeout.
* ftuskip/ftudone event is not fired
* the test did something wrong for example to launch the app directly at the same time lockscreen unlocked.

Comment 26

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #25)
> Without any change: bookmark_web_result_test.js is failing
> Change to appWindowManager: lockscreen_media_playback + bookmark_web_result
> is failing
> 
> The screenshot shows no homescreen and the error message is timeout.
> * ftuskip/ftudone event is not fired
> * the test did something wrong for example to launch the app directly at the
> same time lockscreen unlocked.

I created 2 new patches for different way,
* https://github.com/mozilla-b2g/gaia/pull/25068, tbpl is green, requestForeground each time the app is asked to be displayed even it's already opened.
* https://github.com/mozilla-b2g/gaia/pull/25083 + https://github.com/mozilla-b2g/gaia/pull/25084, still waiting tbpl results. The strategy is ignore screenchange event in LockscreenWindowManager if it's not ready yet.

Comment 27

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #26)
> (In reply to Alive Kuo [:alive][NEEDINFO!] from comment #25)
> > Without any change: bookmark_web_result_test.js is failing
> > Change to appWindowManager: lockscreen_media_playback + bookmark_web_result
> > is failing
> > 
> > The screenshot shows no homescreen and the error message is timeout.
> > * ftuskip/ftudone event is not fired
> > * the test did something wrong for example to launch the app directly at the
> > same time lockscreen unlocked.
> 
> I created 2 new patches for different way,
> * https://github.com/mozilla-b2g/gaia/pull/25068, tbpl is green,
> requestForeground each time the app is asked to be displayed even it's
> already opened.
> * https://github.com/mozilla-b2g/gaia/pull/25083 +
> https://github.com/mozilla-b2g/gaia/pull/25084, still waiting tbpl results.
> The strategy is ignore screenchange event in LockscreenWindowManager if it's
> not ready yet.

Both passed the tests; however while baking v2.1 patch for second way there's new errors.
It seems v2.1 is natively having errors now, experimenting.

Comment 28

[(inactive after 6/18) Alive Kuo [:alive]]

Attachment: Patch for master to change lockscreenWM

This is the patch for master to fix bug 1078110

Comment 29

[(inactive after 6/18) Alive Kuo [:alive]]

Attachment: Patch for 2.1 to change LockscreenWM

@Tapas, this is a different patch from the previous; I need your feedback to see if it's still reproduciable with it.
@Greg, I finally use the internal flag to know lockscreen is ready or not before turning on/off screen. In real world we should be able to know by observing the screen after init logo disappears. Now we didn't implement the strategy so this is my best bet to fix the failure test in v2.1

Comment 30

[Greg Weng [:snowmantw][:gweng][:λ]]

Comment on attachment 8504555 [details] [review]
Patch for master to change lockscreenWM

R+ with nit. Please see the patch page.

Comment 31

[Greg Weng [:snowmantw][:gweng][:λ]]

Comment on attachment 8504557 [details] [review]
Patch for 2.1 to change LockscreenWM

R+ with nit. Please see the patch page.

Comment 32

[bhavana bajaj [:bajaj]]

Checked with Inder and tapas is trying to get feedback on this bug on their side and should have something by tomorrow.

Comment 33

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Comment on attachment 8504557 [details] [review]
Patch for 2.1 to change LockscreenWM

This patch looks good to me  :) 

We have seen this issue in v2.0 and we have seen this issue in v2.1 too. Please create a logging patch for dumping all active windows and other information in logcat from gaia app transition code.

Comment 34

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from comment #33)
> Comment on attachment 8504557 [details] [review]
> Patch for 2.1 to change LockscreenWM
> 
> This patch looks good to me  :) 
> 
> We have seen this issue in v2.0 and we have seen this issue in v2.1 too.
> Please create a logging patch for dumping all active windows and other
> information in logcat from gaia app transition code.

Thanks. 

I think https://bugzilla.mozilla.org/show_bug.cgi?id=1060212 is tracking debugging stuff.

Comment 35

[(inactive after 6/18) Alive Kuo [:alive]]

Master is green, merging.
https://github.com/mozilla-b2g/gaia/commit/5fda9b84375498f8a7baf881508ed3d26452c727

Comment 36

[(inactive after 6/18) Alive Kuo [:alive]]

Comment on attachment 8504557 [details] [review]
Patch for 2.1 to change LockscreenWM

[Approval Request Comment]
[Bug caused by] (feature/regressing bug #):
LockscreenWindowManager implementation
[User impact] if declined:
User is able to open lockscreen even when lockscreen is disable while booting the device and some unexpected behavior might happen.
[Testing completed]: Yes
[Risk to taking this patch] (and alternatives if risky): Riskless small patch to prevent the lockscreen being created before it is ready.
[String changes made]: No

Comment 38

[Ryan VanderMeulen [:RyanVM]]

v2.1: https://github.com/mozilla-b2g/gaia/commit/25a32afc8004607db8be48d6650715a753578462

Comment 39

[Yeojin Chung [:YeojinC]]

Unable to verify. This issue seems like a back and issue and might require automation tests.