1855977 - ExtensionProcessCrashObserver appInForeground flag is set to true when android recreate Fenix application instance in the background after a system restart

Status: VERIFIED FIXED

(WebExtensions :: Android, defect, P1)

Description

[Luca Greco [:rpl] [:luca] [:lgreco]]

The ExtensionProcessCrashObserver's appInForeground boolean flag is currently initially set to true by default and then updated when Gecko notifies the "application-background" / "application-foreground" topics.

"application-background" / "application-foreground" topics are being notified from the GeckoThreadSupport class defined in widget/android/nsAppShell.cpp, in response to the calls of the GeckoThread.onPause and GeckoThread.onResume methods originated from GeckoView's GeckoRuntime java class here.

Under the scenario "Android system starts up Fenix in the background after Android system startup" described in more details below, the appInForeground flag would not be in sync with the actuall application state.

This bug is tracking investigating the issue further, consider tracking how often this is actually happening in practice and determining how to followup to fix it.

Scenario: user starts up Fenix => appInForeground in sync with application state

When the app is started by the user, then moved in the background and foreground by the user, the values set on the ExtensionProcessCrashObserver's appInForeground boolean flag are going to be consistent with the application state as we would expect, because the app going to be intially in the foreground when the user starts it (and so Gecko will also be in the foreground when being started as part of the android app starting up and appIsForeground set initially to true is going to match the initial application state), and then when the user move the app in the background and foreground the android lifecycle methods defined in GeckoRuntime.java linked above will be called and will be notifying the "application-background" / "application-foreground" topics and the appIsForeground will be set to false and true consistently with the application state.

STR:

• start Fenix app from applications drawer
• make sure to enable remote debugging through USB
• open a tab (e.g. to an http url or even just one to about:processes)
• connect to the Fenix app through about:debugging page, connect to the main process, make sure the devtools toolbox is connected to a geckoview.xhtml frame (because that is going to have access to ChromeUtils and other privilged internals), then check that ChromeUtils.importESModule("resource://gre/modules/Extension.sys.mjs").ExtensionProcessCrashObserver._appInForeground is true
• move Fenix in the background and confirm that ExtensionProcessCrashObserver._appInForeground is set to false
• move Fenix back in the foreground and confirm that ExtensionProcessCrashObserver._appInForeground is set to false

Scenario: Android system starts up Fenix in the background after Android system startup => appInForeground NOT in sync set with actual the application state

On the contrary, if then the android system is restarted, while Fenix was previously still technically open (either in the background or in the foreground), then the Android system will be starting Fenix in the background, and GeckoView will be starting Gecko runtime as well, and under this scenario the ExtensionProcessCrashObserver's appInForeground will still be initially set to true even if the application is actually in the background and was never moved in the foreground yet.

If the user at some point move the app in the foreground, then starting from that point the appInForeground flag will then be kept in sync with the application state as in the other scenario, but until that happen, we will not be notifying the "application-background" topic and the appInForeground flag will stay set to true and not in sync with the actual app state.

If under certain conditions the extension process gets started (usually it would not be started just yet) before the user has ever moved the app in the foreground, then the appInForeground flag will not be set to false and because of that:

• the telemetry related to the extension process creation or crashes will be collected as if the app was in the foreground even if it was actually in the background
• extension process crash recovery behaviors tied to the application being in the foreground or in the background are going to not be consistent with the actual application state (e.g. persistent background pages are restarted right away if the app is in the foreground, and because the flag is not in sync with the application state then persistent background page may be restarted right away while the application was still in the background).

Looking through adb logcat into which actual calls to the GeckoRuntime's LifecycleListener methods we get under this scenario, it seems Android system will be trigger a call to onCreate (but no calls to onPause, which in turns means we will not be notifying "application-background" under this scenario as also mentioned above).

STR:

• build a custom Fenix apk with additional logging to print out which is the state of appIsForeground flag when ExtensionProcessCrashObserver init method is called and when the appIsForeground flag is being set when the application-foreground/application-background topics are emitted
• start Fenix app from applications drawer
• make sure to enable remote debugging through USB
• move the app in the background
• reboot the emulator (e.g. connect to the emulator adb shell and the execute reboot from the root user, eventually after running su if the user is not already root, which happens on the emulator after rebooting it from adb)
• after the emulator complete the reboot, and check in adb logcat logs which of the additional logging added in the first step has been emitted in the logcat logs and which was the last value set on appIsForeground based on those logs
• then move the app in foreground and check in adb logcat logs if any of the additional logs have been emitted in logcat
• then move the app in background and check in adb logcat logs if any of the additional logs have been emitted in logcat

Comment 1

[Luca Greco [:rpl] [:luca] [:lgreco]]

Attachment: Bug 1855977 - Set ExtensionProcessCrashObserver appInForeground flag to false if GeckoView is in background when Gecko main process is being started.

Comment 2

[Zac McKenney [:zmckenney]]

:rpl I think we'll want to fix any issues you're seeing with the onPause in GeckoRuntime. I'm curious how you're seeing the onCreate but no calls to onPause. I looked at the ADB logcat of both GV and Fenix and they seem to log the appropriate lifecycle events which would mean we shouldn't have an issue with using this as our means of determining the foreground state.

Comment 3

[Zac McKenney [:zmckenney]]

Nevermind, I see what you're referring to and this is just a misunderstanding of where we determine "foreground". onCreate does not indicate the foreground state. As the code is currently written is correct and onResume is determining the foreground state. It also doesn't fire GeckoThread.onResume() without an onPause already having been called which means there is no foreground state notification. If the thread created in Gecko requires a background notification then that is an inversion of the default within GeckoRuntime for mPaused and one of them will probably need to be adjusted.

Comment 4

[Luca Greco [:rpl] [:luca] [:lgreco]]

QA STRs

NOTE: the GeckoRuntime: Lifecycle ... logs may only be logged in Fenix Nightly debug builds. The addons.process-crash-observer logs instead should still be logged in a non-debug Fenix Nightly builds after flipping the extensions.logging.enabled pref as described below.

Initial setup

• Open about:config in a new Fenix Nightly tab and set extensions.logging.enabled pref to true
• open the Android application list and remove Fenix from it to close it
• watch logcat logs and filter them for the strings GeckoRuntime and addons.process-crash-observer (either from a terminal using adb logcat and grep, or adb logcat tool part of the AndroidStudio IDE), e.g. running the following command from the terminal on Linux or MacOS:

adb logcat -v color | grep -E 'addons\.process-crash-observer|GeckoRuntime'

Scenario 1: User starts Fenix from the applications drawer

• Open the Android applications drawer and click on the Fenix Nightly app icon
• In the adb logcat logs we expect the following messages to be emitted right after that:

GeckoRuntime: Lifecycle: onCreate
GeckoRuntime: Lifecycle: onStart
GeckoRuntime: Lifecycle: onResume
GeckoConsole: ... addons.process-crash-observer DEBUG Detected Android application moved in the foreground (geckoview-initial-foreground)

• Move Fenix in the background by pushing it in the application list using the Android Home button
• In the adb logcat logs we expect the following messages to be emitted right after that:

GeckoRuntime: Lifecycle: onPause
GeckoConsole: ... addons.process-crash-observer DEBUG Detected Android application moved in the background

• NOTE: in some case (not always beingt hit) Android doesn't seem to be calling onPause right away when just moving Fenix in the background, if that is hit we still expect onPause (and the addons.process-crash-observer message right below it in the section right above) right after either: selecting another app or locking the screen of the emulator or phone

• Open the application list and select Fenix to bring it back to the foreground

• In the adb logcat logs we expect the following messages to be emitted right after that:

GeckoRuntime: Lifecycle: onStart
GeckoRuntime: Lifecycle: onResume
GeckoConsole: ... addons.process-crash-observer DEBUG Detected Android application moved in the foreground

Scenario 2: previously running Fenix app recreated in the background after an android reboot

• Make sure Fenix application is running either in foreground or in background
• Reboot the phone or emulator (the emulator can be rebooted from adb shell by executing the reboot command)
• OPTIONAL: Reconnect to the logcat logs (adb logcat exits if it was running when the device or emulator is being rebooted) with the same filtered strings as mentioned in the "Initial setup" section, possibly early enough while the android system is still booting
• If logcat was connected to the android system early enough we expect to only see the following GeckoRuntime Lifecycle log:

GeckoRuntime: Lifecycle: onCreate

• Open the application list and select Fenix to bring it back to the foreground

GeckoRuntime: Lifecycle: onStart
GeckoRuntime: Lifecycle: onResume
GeckoConsole: ... addons.process-crash-observer DEBUG Detected Android application moved in the foreground (geckoview-initial-foreground)

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d7905ac8cf27
Set ExtensionProcessCrashObserver appInForeground flag to false if GeckoView is in background when Gecko main process is being started. r=geckoview-reviewers,willdurand,zmckenney

Comment 6

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/d7905ac8cf27

Comment 7

[Alex Cornestean]

Verified as Fixed. Tested using the latest Fenix debug build 1.0.2341 (Build #1), GV: 120.0a1-20231011211944, AS: 120.20231012050441 using an Oppo Reno6 5G running Android 13.

Following the STR from Comment 4 I obtained the following results:

• Scenario 1:

10-12 10:58:36.994 4441 4441 D GeckoRuntime: Lifecycle: onCreate
10-12 10:58:38.449 4441 4441 D GeckoRuntime: Lifecycle: onStart
10-12 10:58:38.473 4441 4441 D GeckoRuntime: Lifecycle: onResume
10-12 10:58:38.579 4441 6265 I GeckoConsole: 1697097518579 addons.process-crash-observer DEBUG Detected Android application moved in the foreground (geckoview-initial-foreground)

10-12 10:58:44.598 4441 4441 D GeckoRuntime: Lifecycle: onPause
10-12 10:58:44.602 4441 6265 I GeckoConsole: 1697097524601 addons.process-crash-observer DEBUG Detected Android application moved in the background

10-12 10:58:51.473 4441 4441 D GeckoRuntime: Lifecycle: onStart
10-12 10:58:51.479 4441 4441 D GeckoRuntime: Lifecycle: onResume
10-12 10:58:51.481 4441 6265 I GeckoConsole: 1697097531481 addons.process-crash-observer DEBUG Detected Android application moved in the foreground

• Scenario 2:

10-12 11:12:16.848 7427 7427 D GeckoRuntime: Lifecycle: onCreate

10-12 11:12:18.057 7427 7427 D GeckoRuntime: Lifecycle: onStart
10-12 11:12:18.063 7427 7427 D GeckoRuntime: Lifecycle: onResume
10-12 11:12:18.064 7427 7530 I GeckoConsole: 1697098338064 addons.process-crash-observer DEBUG Detected Android application moved in the foreground (geckoview-initial-foreground)

Both results are as described in Comment 4, confirming the fix.

Comment 8

[Luca Greco [:rpl] [:luca] [:lgreco]]

Comment on attachment 9355922 [details]
Bug 1855977 - Set ExtensionProcessCrashObserver appInForeground flag to false if GeckoView is in background when Gecko main process is being started.

Beta/Release Uplift Approval Request

• User impact if declined: On Android builds the value returned by the ExtensionProcessCrashObserver's appInForeground is being used to determine if extension process crash should be handled differently (e.g. persistent background page will be reloaded right away only if the application is in the foreground).

Without the fix attached to this bugzilla issue, the ExtensionProcessCrashObserver's appInForeground flag may not be matching the actual state of the android application is some scenario (e.g. after a system reboot as described in more detail in comment 0) and the expected special handling may be activated while the android app is not really in that state.

(Technically only Android builds are affected by this issue, and the change does not change any behaviors on Desktop builds).

• Is this code covered by automated tests?: No
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: Yes
• If yes, steps to reproduce: Same as STR used to verify in Nightly in comment 4 (eventually without expecting the GeckoRuntime Lifecycle logs to be logged if verified in a non debug Fenix build, as also mentioned in comment 4).
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): The patch is small and shouldn't have any impact on anything but the ExtensionProcessCrashObserver's appInForeground flag. The fix has been explicitly QA verified in nightly and no issue or regression has been reported us so far.
• String changes made/needed:
• Is Android affected?: Yes

Comment 9

[Donal Meehan [:dmeehan]]

Comment on attachment 9355922 [details]
Bug 1855977 - Set ExtensionProcessCrashObserver appInForeground flag to false if GeckoView is in background when Gecko main process is being started.

Approved for Desktop and Fenix 119.0b9

Comment 10

[Pulsebot]

https://hg.mozilla.org/releases/mozilla-beta/rev/c7c9a2e58f04

Comment 11

[Alex Cornestean]

Verified as Fixed. Tested using the latest Fenix Beta 119.0b9 (Build #2015979707), d30a10afe7+, GV: 119.0-20231013091412, AS: 119.0 using an Oppo Reno6 5G running Android 13.

Following the STR from Comment 4 I obtained the following results:

Scenario 1:
1697455417417 addons.process-crash-observer DEBUG Detected Android application moved in the foreground (geckoview-initial-foreground)
1697455429892 addons.process-crash-observer DEBUG Detected Android application moved in the background
1697455445530 addons.process-crash-observer DEBUG Detected Android application moved in the foreground

Scenario 2:
1697455928044 addons.process-crash-observer DEBUG Detected Android application moved in the foreground (geckoview-initial-foreground)

Both results are as described in Comment 4, confirming the fix.