Open Bug 1840443 Opened 2 years ago Updated 4 hours ago

geckodriver fails with "adb error: fchown failed: Operation not permitted" on Android 11 and later

Categories

(Testing :: geckodriver, defect, P2)

Default
defect

Tracking

(Not tracked)

ASSIGNED

People

(Reporter: whimboo, Assigned: mleclair, NeedInfo)

References

(Blocks 1 open bug, )

Details

(Whiteboard: [webdriver:backlog])

Attachments

(1 file)

Reported via: https://github.com/mozilla/geckodriver/issues/1885#issuecomment-1600259567

Using Android 11 and later geckodriver fails to setup the profile for Firefox and as such bails out early without allowing to run any tests. Here the log file as produced by geckodriver:

1687794900082	mozdevice	TRACE	execute_host_command: >> "shell:ls /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root"
1687794900096	mozdevice	TRACE	execute_host_command: << ""
1687794900096	mozdevice	DEBUG	Creating /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root/org.mozilla.geckoview.test_runner-geckodriver-profile
1687794900097	mozdevice	TRACE	execute_host_command: >> "host:transport:25051FDF6006PA"
1687794900099	mozdevice	TRACE	execute_host_command: << []
1687794900099	mozdevice	TRACE	execute_host_command: >> "shell:mkdir -p /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root/org.mozilla.geckoview.test_runner-geckodriver-profile"
1687794900118	mozdevice	TRACE	execute_host_command: << ""
1687794900118	mozdevice	TRACE	execute_host_command: >> "host:transport:25051FDF6006PA"
1687794900119	mozdevice	TRACE	execute_host_command: << []
1687794900119	mozdevice	TRACE	execute_host_command: >> "shell:chmod  -R 777 /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root/org.mozilla.geckoview.test_runner-geckodriver-profile"
1687794900133	mozdevice	TRACE	execute_host_command: << ""
1687794900139	mozdevice	TRACE	execute_host_command: >> "host:transport:25051FDF6006PA"
1687794900139	mozdevice	TRACE	execute_host_command: << []
1687794900139	mozdevice	TRACE	execute_host_command: >> "shell:am clear-debug-app org.mozilla.geckoview.test_runner"
1687794900182	mozdevice	TRACE	execute_host_command: << ""
1687794900182	geckodriver::android	DEBUG	Disabled reading from configuration file
1687794900182	mozdevice	DEBUG	Deleting /data/local/tmp/org.mozilla.geckoview.test_runner-geckoview-config.yaml
1687794900183	mozdevice	TRACE	execute_host_command: >> "host:transport:25051FDF6006PA"
1687794900183	mozdevice	TRACE	execute_host_command: << []
1687794900183	mozdevice	TRACE	execute_host_command: >> "shell:rm -rf /data/local/tmp/org.mozilla.geckoview.test_runner-geckoview-config.yaml"
1687794900214	mozdevice	TRACE	execute_host_command: << ""
1687794900214	geckodriver::android	DEBUG	Deleted GeckoView configuration file
1687794900214	mozdevice	DEBUG	Deleting /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root
1687794900216	mozdevice	TRACE	execute_host_command: >> "host:transport:25051FDF6006PA"
1687794900216	mozdevice	TRACE	execute_host_command: << []
1687794900216	mozdevice	TRACE	execute_host_command: >> "shell:rm -rf /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root"
1687794900253	mozdevice	TRACE	execute_host_command: << ""
1687794900254	geckodriver::android	DEBUG	Deleted test root folder: /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root
1687794900255	mozdevice	TRACE	execute_host_command: >> "host:transport:25051FDF6006PA"
1687794900255	mozdevice	TRACE	execute_host_command: << []
1687794900255	mozdevice	TRACE	execute_host_command: >> "host-serial:25051FDF6006PA:killforward:tcp:53811"
1687794900255	mozdevice	TRACE	execute_host_command: << ""
1687794900255	geckodriver::android	DEBUG	Marionette port forward (53811 -> 2829) stopped
1687794900256	mozdevice	TRACE	execute_host_command: >> "host:transport:25051FDF6006PA"
1687794900256	mozdevice	TRACE	execute_host_command: << []
1687794900256	mozdevice	TRACE	execute_host_command: >> "host-serial:25051FDF6006PA:killforward:tcp:9222"
1687794900256	mozdevice	TRACE	execute_host_command: << ""
1687794900256	geckodriver::android	DEBUG	WebSocket port forward (9222 -> 9222) stopped
1687794900256	webdriver::server	DEBUG	<- 500 Internal Server Error {"value":{"error":"unknown error","message":"adb error: fchown failed: Operation not permitted","stacktrace":""}}
DEBUG:urllib3.connectionpool:http://localhost:4444 "POST /session HTTP/1.1" 500 113
DEBUG:root:response: {'value': {'error': 'unknown error', 'message': 'adb error: fchown failed: Operation not permitted', 'stacktrace': ''}}
Traceback (most recent call last):

The documentation for the changes can be found at:
https://developer.android.com/about/versions/11/privacy/storage

Maybe we could set the requestLegacyExternalStorage to true for now in the manifest file to keep it working as for Android 10.

I can actually see this problem with a Pixel 6.

Actually I can workaround this problem by using --android-storage=app but then geckodriver fails to start the test_runner package. Interesting is that app doesn't seem to work for others.

Priority: -- → P2
Whiteboard: [webdriver:backlog]

The severity field is not set for this bug.
:whimboo, could you have a look please?

For more information, please visit BugBot documentation.

Flags: needinfo?(hskupin)

While this is a geckodriver issue and not resolved, I just wanted to add for future readers were also able to use the fix of using --android-storage=app to our performance testing code(done in bug 1857623) and this issue is no longer occurring in CI for us on the Pixel 6 devices.

Blocks: 1700559

The workarounds in this bug do not work on the A54 running Android 14. They just crash the browser instead. Is it possible to get this working on devices other than the Pixel 6?

So, I've made some progress: passing --android-storage=internal at least launches Firefox, where --android-storage=auto fails with the fchown error, and --android-storage=app simply hangs.

In logcat:

"app"

02-14 11:42:32.630 22838 22838 I GeckoRuntime: Adding debug configuration from: /data/local/tmp/org.mozilla.firefox-geckoview-config.yaml
02-14 11:42:32.631 22838 22872 I GeckoThread: preparing to run Gecko
02-14 11:42:32.632 22838 22872 D nativeloader: Load /data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64/libmozglue.so using ns clns-6 from class loader (caller=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/base.apk!classes3.dex): ok
02-14 11:42:32.634  1623  4555 D CompatibilityChangeReporter: Compat change id reported: 161145287; UID 10278; state: ENABLED
02-14 11:42:32.635 22838 22872 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:42:32.636 22838 22872 W Settings: Setting animator_duration_scale has moved from android.provider.Settings.System to android.provider.Settings.Global, returning read-only global URI.
02-14 11:42:32.637 22838 22872 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:42:32.638 22838 22872 E GeckoLibLoad: Load sqlite start
02-14 11:42:32.638 22838 22872 E GeckoLibLoad: Load sqlite done
02-14 11:42:32.638 22838 22872 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:42:32.638 22838 22872 E GeckoLibLoad: Load nss start
02-14 11:42:32.638 22838 22872 E GeckoLibLoad: Load nss done
02-14 11:42:32.638 22838 22872 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:42:32.638 22838 22872 E GeckoLibLoad: Loaded libs in 0.213338ms total, 0ms(0ms) user, 0ms(0ms) system, 0(0) faults
02-14 11:42:32.639 22838 22872 W GeckoThread: zerdatime 37636049 - runGecko
02-14 11:42:32.641 22838 22872 E GeckoRuntime: Could not find profile folder.
02-14 11:42:32.642 22838 22872 I mozglue : XRE_main returned 1
02-14 11:42:32.666 22838 22890 E SearchMiddleware: Could not find migrated default search engine ()
02-14 11:42:32.676 22838 22877 D CompatibilityChangeReporter: Compat change id reported: 263076149; UID 10278; state: ENABLED
02-14 11:42:32.677 22838 22838 I BgSyncManager: Periodic syncing enabled: PeriodicSyncConfig(periodMinutes=240, initialDelayMinutes=5)
02-14 11:42:32.678 22838 22838 I FirefoxAccountStateMachine: Sync is enabled
02-14 11:42:32.687 22838 22838 I FenixApplication: AutoPushFeature is configured, initializing it...
02-14 11:42:32.688 22838 22838 I AbstractFirebasePushService: start
02-14 11:42:32.695 22838 22838 D AndroidRuntime: Shutting down VM
02-14 11:42:32.695 22838 22838 E AndroidRuntime: FATAL EXCEPTION: main
02-14 11:42:32.695 22838 22838 E AndroidRuntime: Process: org.mozilla.firefox, PID: 22838
02-14 11:42:32.695 22838 22838 E AndroidRuntime: java.lang.RuntimeException: GeckoRuntime is shutting down
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at com.google.firebase.components.OptionalProvider$$ExternalSyntheticLambda0.onShutdown(R8$$SyntheticClass:5)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at org.mozilla.geckoview.GeckoRuntime$1.handleMessage(GeckoRuntime.java:31)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at org.mozilla.gecko.EventDispatcher$3.run(EventDispatcher.java:13)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at android.os.Handler.handleCallback(Handler.java:959)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at android.os.Handler.dispatchMessage(Handler.java:100)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at android.os.Looper.loopOnce(Looper.java:232)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at android.os.Looper.loop(Looper.java:317)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at android.app.ActivityThread.main(ActivityThread.java:8592)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at java.lang.reflect.Method.invoke(Native Method)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:580)
02-14 11:42:32.695 22838 22838 E AndroidRuntime: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:878)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: Uncaught exception handled:
02-14 11:42:32.695 22838 22838 E ExceptionHandler: java.lang.RuntimeException: GeckoRuntime is shutting down
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at com.google.firebase.components.OptionalProvider$$ExternalSyntheticLambda0.onShutdown(R8$$SyntheticClass:5)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at org.mozilla.geckoview.GeckoRuntime$1.handleMessage(GeckoRuntime.java:31)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at org.mozilla.gecko.EventDispatcher$3.run(EventDispatcher.java:13)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at android.os.Handler.handleCallback(Handler.java:959)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at android.os.Handler.dispatchMessage(Handler.java:100)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at android.os.Looper.loopOnce(Looper.java:232)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at android.os.Looper.loop(Looper.java:317)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at android.app.ActivityThread.main(ActivityThread.java:8592)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at java.lang.reflect.Method.invoke(Native Method)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:580)
02-14 11:42:32.695 22838 22838 E ExceptionHandler: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:878)
02-14 11:42:32.695 22838 22838 I mozac/CrashReporter: Received crash: UncaughtExceptionCrash(timestamp=1739558552695, throwable=java.lang.RuntimeException: GeckoRuntime is shutting down, breadcrumbs=[], runtimeTags={}, uuid=0f09e477-1d36-4d81-8d4b-92e1d04f5abd)

While it hangs there's reams of

02-14 11:42:33.653  1178  1178 E adbd    : failed to connect to socket 'tcp:2829': Connection refused

"internal"

02-14 11:48:13.489 23784 23784 I GeckoRuntime: Adding debug configuration from: /data/local/tmp/org.mozilla.firefox-geckoview-config.yaml
02-14 11:48:13.489 23784 23818 I GeckoThread: preparing to run Gecko
02-14 11:48:13.490 23784 23818 D nativeloader: Load /data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64/libmozglue.so using ns clns-6 from class loader (caller=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/base.apk!classes3.dex): ok
02-14 11:48:13.493  1623  2489 D CompatibilityChangeReporter: Compat change id reported: 161145287; UID 10278; state: ENABLED
02-14 11:48:13.493 23784 23818 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:48:13.494 23784 23818 W Settings: Setting animator_duration_scale has moved from android.provider.Settings.System to android.provider.Settings.Global, returning read-only global URI.
02-14 11:48:13.494 23784 23818 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:48:13.495 23784 23818 E GeckoLibLoad: Load sqlite start
02-14 11:48:13.495 23784 23818 E GeckoLibLoad: Load sqlite done
02-14 11:48:13.495 23784 23818 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:48:13.495 23784 23818 E GeckoLibLoad: Load nss start
02-14 11:48:13.495 23784 23818 E GeckoLibLoad: Load nss done
02-14 11:48:13.495 23784 23818 I GeckoLoader: Library base=/data/app/~~85Us7jwpLengGGN-FIAKzA==/org.mozilla.firefox-WChWW76R8Pe0v8ySMVgs9A==/lib/arm64
02-14 11:48:13.495 23784 23818 E GeckoLibLoad: Loaded libs in 0.182943ms total, 0ms(0ms) user, 0ms(0ms) system, 0(0) faults
02-14 11:48:13.496 23784 23818 W GeckoThread: zerdatime 37976906 - runGecko
02-14 11:48:13.498   987  1136 I WifiHAL : Creating message to get link statistics; iface = 47
02-14 11:48:13.496 23784 23784 W Gecko   : type=1400 audit(0.0:2252): avc:  denied  { write } for  name="org.mozilla.firefox-geckodriver-profile" dev="dm-53" ino=46742 scontext=u:r:untrusted_app:s0:c22,c257,c512,c768 tcontext=u:object_r:shell_data_file:s0 tclass=dir permissive=0 app=org.mozilla.firefox
02-14 11:48:13.496 23784 23784 W Gecko   : type=1400 audit(0.0:2253): avc:  denied  { write } for  name="org.mozilla.firefox-geckodriver-profile" dev="dm-53" ino=46742 scontext=u:r:untrusted_app:s0:c22,c257,c512,c768 tcontext=u:object_r:shell_data_file:s0 tclass=dir permissive=0 app=org.mozilla.firefox

Then lots of

02-14 11:48:14.720  1178  1178 E adbd    : failed to connect to socket 'tcp:2829': Connection refused
02-14 11:48:14.720 23784 23784 W Gecko   : type=1400 audit(0.0:2276): avc:  denied  { write } for  name="org.mozilla.firefox-geckodriver-profile" dev="dm-53" ino=46742 scontext=u:r:untrusted_app:s0:c22,c257,c512,c768 tcontext=u:object_r:shell_data_file:s0 tclass=dir permissive=0 app=org.mozilla.firefox
02-14 11:48:14.833  1178  1178 E adbd    : failed to connect to socket 'tcp:2829': Connection refused
02-14 11:48:14.947  1178  1178 E adbd    : failed to connect to socket 'tcp:2829': Connection refused
02-14 11:48:15.063  1178  1178 E adbd    : failed to connect to socket 'tcp:2829': Connection refused

and eventually Firefox exits.

02-14 11:48:18.660 23784 23818 I Gecko:DumpUtils: Fifo watcher disabled via pref.
02-14 11:48:18.660 23784 23784 W org.mozilla.firefox: type=1400 audit(0.0:2350): avc:  denied  { bind } for  comm=4E65746C696E6B204D6F6E69746F72 scontext=u:r:untrusted_app:s0:c22,c257,c512,c768 tcontext=u:r:untrusted_app:s0:c22,c257,c512,c768 tclass=netlink_route_socket permissive=0 bug=b/155595000 app=org.mozilla.firefox
02-14 11:48:18.700 23784 23784 W Gecko   : type=1400 audit(0.0:2351): avc:  denied  { write } for  name="org.mozilla.firefox-geckodriver-profile" dev="dm-53" ino=46742 scontext=u:r:untrusted_app:s0:c22,c257,c512,c768 tcontext=u:object_r:shell_data_file:s0 tclass=dir permissive=0 app=org.mozilla.firefox
02-14 11:48:18.716 23784 23818 W mozilla.firefox: Accessing hidden field Ljava/lang/Boolean;->value:Z (max-target-p, JNI, denied)
02-14 11:48:18.716 23784 23818 W mozilla.firefox: Accessing hidden field Ljava/lang/Integer;->value:I (max-target-p, JNI, denied)
02-14 11:48:18.716 23784 23818 W mozilla.firefox: Accessing hidden field Ljava/lang/Double;->value:D (max-target-p, JNI, denied)
02-14 11:48:18.720  1623  1730 D GrammaticalInflection: The flag must be enabled to allow calling the API.
02-14 11:48:18.721  1623  1730 D CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10278; state: DISABLED
02-14 11:48:18.721  1623  1730 D CompatibilityChangeReporter: Compat change id reported: 177438394; UID 10278; state: DISABLED
02-14 11:48:18.721  1623  1730 D CompatibilityChangeReporter: Compat change id reported: 135772972; UID 10278; state: DISABLED
02-14 11:48:18.721  1623  1730 D CompatibilityChangeReporter: Compat change id reported: 135754954; UID 10278; state: ENABLED
02-14 11:48:18.721  1623  1780 D CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10278; state: ENABLED
02-14 11:48:18.735   916   916 D Zygote  : Forked child process 23963
02-14 11:48:18.736  1623  1780 I ActivityManager: Start proc 23963:org.mozilla.firefox:tab35/u0a278 for service {org.mozilla.firefox/org.mozilla.gecko.process.GeckoChildProcessServices$tab35}
02-14 11:48:18.745 23963 23963 I a.firefox:tab35: Using CollectorTypeCMC GC.
02-14 11:48:18.750  1178  1214 I adbd    : jdwp connection from 23963
02-14 11:48:18.752 23963 23963 D nativeloader: Load libframework-connectivity-tiramisu-jni.so using APEX ns com_android_tethering for caller /apex/com.android.tethering/javalib/framework-connectivity-t.jar: ok
02-14 11:48:18.755 23784 23784 D AndroidRuntime: Shutting down VM
02-14 11:48:18.755 23784 23784 E AndroidRuntime: FATAL EXCEPTION: main
02-14 11:48:18.755 23784 23784 E AndroidRuntime: Process: org.mozilla.firefox, PID: 23784
02-14 11:48:18.755 23784 23784 E AndroidRuntime: java.lang.RuntimeException: GeckoRuntime is shutting down
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at com.google.firebase.components.OptionalProvider$$ExternalSyntheticLambda0.onShutdown(R8$$SyntheticClass:5)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at org.mozilla.geckoview.GeckoRuntime$1.handleMessage(GeckoRuntime.java:31)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at org.mozilla.gecko.EventDispatcher$3.run(EventDispatcher.java:13)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at android.os.Handler.handleCallback(Handler.java:959)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at android.os.Handler.dispatchMessage(Handler.java:100)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at android.os.Looper.loopOnce(Looper.java:232)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at android.os.Looper.loop(Looper.java:317)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at android.app.ActivityThread.main(ActivityThread.java:8592)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at java.lang.reflect.Method.invoke(Native Method)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:580)
02-14 11:48:18.755 23784 23784 E AndroidRuntime: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:878)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: Uncaught exception handled:
02-14 11:48:18.755 23784 23784 E ExceptionHandler: java.lang.RuntimeException: GeckoRuntime is shutting down
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at com.google.firebase.components.OptionalProvider$$ExternalSyntheticLambda0.onShutdown(R8$$SyntheticClass:5)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at org.mozilla.geckoview.GeckoRuntime$1.handleMessage(GeckoRuntime.java:31)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at org.mozilla.gecko.EventDispatcher$3.run(EventDispatcher.java:13)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at android.os.Handler.handleCallback(Handler.java:959)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at android.os.Handler.dispatchMessage(Handler.java:100)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at android.os.Looper.loopOnce(Looper.java:232)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at android.os.Looper.loop(Looper.java:317)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at android.app.ActivityThread.main(ActivityThread.java:8592)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at java.lang.reflect.Method.invoke(Native Method)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:580)
02-14 11:48:18.755 23784 23784 E ExceptionHandler: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:878)
02-14 11:48:18.756 23784 23784 I mozac/CrashReporter: Received crash: UncaughtExceptionCrash(timestamp=1739558898755, throwable=java.lang.RuntimeException: GeckoRuntime is shutting down, breadcrumbs=[Breadcrumb(message=fxa-state-machine-checker: a-c transition started (event: Account.Start), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=fxa-state-machine-checker: a-c transition (event: Account.Start, into: ProgressState.Initializing), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=fxa_client::state_machine::checker[99]: fxa-state-machine-checker: public transition start (Initialize -> GetAthState) (0), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=fxa_client::state_machine::checker[201]: fxa-state-machine-checker: check_internal_state successful GetAthState (1), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=fxa_client::state_machine::checker[129]: fxa-state-machine-checker: internal transition (GetAthStateSuccess -> Complete(Disconnected)) (2), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=fxa_client::state_machine::checker[133]: fxa-state-machine-checker: public transition end (3), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=fxa-state-machine-checker: a-c transition (event: Progress.AccountNotFound, into: AccountState.NotAthenticated), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=fxa_client::state_machine::checker[180]: fxa-state-machine-checker: check_public_state successful Disconnected (4), data={}, category=, level=DEBUG, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=onCreate(), data={recreated=false, intent=android.intent.action.VIEW, instance=65687414}, category=HomeActivity, level=INFO, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=Changing to fragment browserFragment, isCustomTab: false, data={}, category=DestinationChanged, level=INFO, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=onAttach(), data={instance=225159853, activityInstance=65687414, activityName=HomeActivity}, category=BrowserFragment, level=INFO, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=onCreateView(), data={customTabSessionId=null, instance=225159853, activityInstance=65687414, activityName=HomeActivity}, category=BrowserFragment, level=INFO, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=onStart(), data={instance=65687414}, category=HomeActivity, level=INFO, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025), Breadcrumb(message=onResume(), data={instance=65687414}, category=HomeActivity, level=INFO, type=DEFAULT, date=Fri Feb 14 11:48:13 MST 2025)], runtimeTags={}, uuid=b2291ed2-4607-4712-a9e6-4bffc20d7ca3)
02-14 11:48:18.763 23963 23963 D CompatibilityChangeReporter: Compat change id reported: 171979766; UID 10278; state: ENABLED

I'll keep looking at this after lunch.

Oh and

"sdcard"

02-14 13:39:35.024  1623  1834 I AppsFilter: interaction: PackageSetting{3df00d6 org.mozilla.geckoview_example/10316} -> PackageSetting{9fa8e17 org.mozilla.firefox/10278} BLOCKED
02-14 13:39:35.024  1623  1834 I AppsFilter: interaction: PackageSetting{4402a44 com.google.android.microdroid.empty_payload/10273} -> PackageSetting{9fa8e17 org.mozilla.firefox/10278} BLOCKED

OK so I've done some spelunking here, and what to summarize what I think I know (and I'm very open to being proved wrong here) and propose a path forward which should fix this once and for all. My goal here being that we should be able to use browsertime -b firefox --android and have it work even on release, on a non-rooted phone.

So my understanding is as follows: GeckoDriver works by creating a new profile directory with a number of preferences set in user.js then launching firefox with said profile. On Android there's a number of different ways this used to be working (captured in the "android-storage" arg)

  • "app": use /data/data/<PACKAGE_NAME>. I think this only works for debuggable apps, unless the phone is rooted.
  • "internal": use /data/local/tmp/test_root/: Only works on rooted phones that can disable SELinux
  • "sdcard": use $EXTERNAL_STORAGE/Android/data/<PACKAGE>/files/test_root -- this fails but I haven't yet been able to make heads or tails of what's going on .

A particularly awkward problem here occurs: It is possible for geckodriver to end up putting Firefox into a non-launchable state. E.g. I just ran

browsertime --android -b firefox http://example.com --firefox.geckodriverArgs="--android-storage" --firefox.geckodriverArgs="app"  --skipHar --iterations 1 

which hung. So I killed it. But now adb shell settings get global debug_app reports org.mozilla.firefox, as the debug app, and I can't launch firefox because

$ cat org.mozilla.firefox-geckoview-config.yaml                                                                                                                                                                                                                                                                                     
## GeckoView configuration YAML
##
## Auto-generated by geckodriver.
## See https://mozilla.github.io/geckoview/consumer/docs/automation.
---
env:
  MOZ_CRASHREPORTER: "1"
  MOZ_CRASHREPORTER_NO_REPORT: "1"
  MOZ_CRASHREPORTER_SHUTDOWN: "1"
args:
  - "--marionette"
  - "--profile"
  - /data/data/org.mozilla.firefox/test_root/org.mozilla.firefox-geckodriver-profile
  - "-no-remote"
  - "--remote-debugging-port"
  - "9222"
  - "--remote-allow-hosts"
  - localhost

which isn't working is set.

My proposal for how this could work (would need to ride the trains likely). For GeckoView, instead of trying to set the profile via the args: array in the YAML file, instead we should add a new section to the YAML file. There's a number of designs possible here, but what I'd propose is that we add profile_copy which specifies a path. That path is then recursively copied inside of one of the app directories, and that newly copied directory is used as the profile directory, rather than context.getFilesDir().getPath(). After the copy succeeds, the original directory should be deleted.

If GeckoView starts up and sees profile_copy, but there is no directory, it should ignore the rest of the config file and launch as if firefox isn't a debuggable app. This avoids the case where you get into a broken state from having the YAML file hang around.

What do you think Henrik, Irene?

I think I could write this patch if you approve of the approach.

Flags: needinfo?(bugzeeeeee)

Another option (Which might already work via release) would be just setting all the prefs in user.js via the prefs in org.mozilla.firefox-geckoview-config.yaml...

Assignee: nobody → mleclair
Status: NEW → ASSIGNED

I posted a workaround for now to use geckodriver. It really just is a bandaid fix, definitely not a long term solution haha

(In reply to Matthew Gaudet (he/him) [:mgaudet] from comment #7)

OK so I've done some spelunking here, and what to summarize what I think I know (and I'm very open to being proved wrong here) and propose a path forward which should fix this once and for all. My goal here being that we should be able to use browsertime -b firefox --android and have it work even on release, on a non-rooted phone.

Thank you for starting to take a look at it. I'm still blocked in not having a way to test this due to missing devices.

which hung. So I killed it. But now adb shell settings get global debug_app reports org.mozilla.firefox, as the debug app, and I can't launch firefox because

$ cat org.mozilla.firefox-geckoview-config.yaml                                                                                                                                                                                                                                                                                     
## GeckoView configuration YAML

Yes, this is a known problem and covered by bug 1699988. Feel free to work on it separately if you have a bit of time. Sadly I was not able to include it in the upcoming 0.36.0 release of geckodriver.

If GeckoView starts up and sees profile_copy, but there is no directory, it should ignore the rest of the config file and launch as if firefox isn't a debuggable app. This avoids the case where you get into a broken state from having the YAML file hang around.

Would this still be an issue when the YAML file is always deleted? I assume it's unrelated to the --android-storage argument, right?

Flags: needinfo?(hskupin)

I can say: Marc Leclair's workaround patch -does work- on my machine with --android-storage=auto.

That's huge. I know Marc says it's a bandaid, but it's one which may be worthwhile to shape into something.

I would be willing to push on the copy-directory solution as a longer term solve, and I'll peek at 1699988.

If GeckoView starts up and sees profile_copy, but there is no directory, it should ignore the rest of the config file and launch as if firefox isn't a debuggable app. This avoids the case where you get into a broken state from having the YAML file hang around.

Would this still be an issue when the YAML file is always deleted? I assume it's unrelated to the --android-storage argument, right?

Oh yes, that's unrelated, and basically bug 1699988.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: