search

mozilla / geckodriver

WebDriver for Firefox
https://firefox-source-docs.mozilla.org/testing/geckodriver/
Mozilla Public License 2.0
7.03k stars 1.51k forks source link

adb error: couldn't create file: Permission denied #2092

Open AlexandraMoga opened 1 year ago

AlexandraMoga commented 1 year ago

System

Testcase

I'm simply traying to launch Firefox on an android device (Pixel 5, Android 11 emulator with Android studio) using the capabilities suggested in this documentation but the session hangs and finally exists with error adb error: couldn't create file: Permission denied. I'm not sure if there is some issue at my side (capabilities are visible in the stacktrace) or if this is a geckodriver issue.

Stacktrace

[HTTP] --> POST /session
[HTTP] {"capabilities":{"firstMatch":[{}],"alwaysMatch":{"appium:automationName":"Gecko","browserName":"Firefox","platformName":"windows","moz:firefoxOptions":{"androidPackage":"org.mozilla.fenix"}}}}
[debug] [AppiumDriver@20f2] Calling AppiumDriver.createSession() with args: [null,null,{"firstMatch":[{}],"alwaysMatch":{"appium:automationName":"Gecko","browserName":"Firefox","platformName":"windows","moz:firefoxOptions":{"androidPackage":"org.mozilla.fenix"}}}]
[debug] [AppiumDriver@20f2] Event 'newSessionRequested' logged at 1677594344443 (16:25:44 GMT+0200 (Eastern European Standard Time))
[Appium] Attempting to find matching driver for automationName 'Gecko' and platformName 'windows'
[Appium] The 'gecko' driver was installed and matched caps.
[Appium] Will require it at C:\Users\USER\.appium\node_modules\appium-geckodriver
[debug] [Appium] Requiring driver at C:\Users\USER\.appium\node_modules\appium-geckodriver
[AppiumDriver@20f2] Appium v2.0.0-beta.56 creating new GeckoDriver (v1.1.8) session
[AppiumDriver@20f2] Checking BaseDriver versions for Appium and GeckoDriver
[AppiumDriver@20f2] Appium's BaseDriver version is 9.3.2
[AppiumDriver@20f2] GeckoDriver's BaseDriver version is 9.3.2
[debug] [GeckoDriver@7133] Creating session with W3C capabilities: {
[debug] [GeckoDriver@7133]   "alwaysMatch": {
[debug] [GeckoDriver@7133]     "browserName": "Firefox",
[debug] [GeckoDriver@7133]     "platformName": "windows",
[debug] [GeckoDriver@7133]     "moz:firefoxOptions": {
[debug] [GeckoDriver@7133]       "androidPackage": "org.mozilla.fenix"
[debug] [GeckoDriver@7133]     },
[debug] [GeckoDriver@7133]     "appium:automationName": "Gecko"
[debug] [GeckoDriver@7133]   },
[debug] [GeckoDriver@7133]   "firstMatch": [
[debug] [GeckoDriver@7133]     {}
[debug] [GeckoDriver@7133]   ]
[debug] [GeckoDriver@7133] }
[GeckoDriver@7133 (736c9dd5)] Session created with session id: 736c9dd5-c0c3-4a40-99e2-a14304080bab
[GeckoDriver@7133 (736c9dd5)] Starting 'C:\Users\USER\AppData\Local\Programs\Python\Python39\geckodriver.exe' with args ["-p",5200]
[debug] [GeckoDriver@7133 (736c9dd5)] Matched '/status' to command name 'getStatus'
[debug] [GeckoDriver@7133 (736c9dd5)] Proxying [GET /status] to [GET http://127.0.0.1:5200/status] with no body
[GeckoDriver@7133 (736c9dd5)] connect ECONNREFUSED 127.0.0.1:5200
[debug] [GeckoDriver@7133 (736c9dd5)] [geckodriver.exe] 1677594345068   geckodriver     INFO    Listening on 127.0.0.1:5200
[debug] [GeckoDriver@7133 (736c9dd5)] Matched '/status' to command name 'getStatus'
[debug] [GeckoDriver@7133 (736c9dd5)] Proxying [GET /status] to [GET http://127.0.0.1:5200/status] with no body
[debug] [GeckoDriver@7133 (736c9dd5)] Got response with status 200: {"value":{"message":"","ready":true}}
[debug] [GeckoDriver@7133 (736c9dd5)] Matched '/session' to command name 'createSession'
[debug] [GeckoDriver@7133 (736c9dd5)] Proxying [POST /session] to [POST http://127.0.0.1:5200/session] with body: {"capabilities":{"firstMatch":[{}],"alwaysMatch":{"browserName":"firefox","platformName":"windows","moz:firefoxOptions":{"androidPackage":"org.mozilla.fenix"}}}}
[debug] [GeckoDriver@7133 (736c9dd5)] [geckodriver.exe] 1677594353781   mozdevice       INFO    Device is rooted
[GeckoDriver@7133 (736c9dd5)] Got response with status 500: {"value":{"error":"unknown error","message":"adb error: couldn't create file: Permission denied","stacktrace":""}}
[debug] [W3C] Matched W3C error code 'unknown error' to UnknownError
[GeckoDriver@7133 (736c9dd5)] Ending Gecko Driver session
[GeckoDriver@7133 (736c9dd5)] geckodriver.exe has exited with code null, signal SIGTERM
[debug] [AppiumDriver@20f2] Event 'newSessionStarted' logged at 1677594393012 (16:26:33 GMT+0200 (Eastern European Standard Time))
[debug] [AppiumDriver@20f2] Encountered internal error running command: UnknownError: An unknown server-side error occurred while processing the command. Original error: adb error: couldn't create file: Permission denied
[debug] [AppiumDriver@20f2]     at errorFromW3CJsonCode (C:\Users\USER\AppData\Roaming\nvm\v18.14.2\node_modules\appium\node_modules\@appium\base-driver\lib\protocol\errors.js:1034:25)
[debug] [AppiumDriver@20f2]     at ProxyRequestError.getActualError (C:\Users\USER\AppData\Roaming\nvm\v18.14.2\node_modules\appium\node_modules\@appium\base-driver\lib\protocol\errors.js:909:14)
[debug] [AppiumDriver@20f2]     at GeckoProxy.command (C:\Users\USER\AppData\Roaming\nvm\v18.14.2\node_modules\appium\node_modules\@appium\base-driver\lib\jsonwp-proxy\proxy.js:340:19)
[debug] [AppiumDriver@20f2]     at processTicksAndRejections (node:internal/process/task_queues:95:5)
[debug] [AppiumDriver@20f2]     at GeckoDriverServer.start (C:\Users\USER\.appium\node_modules\appium-geckodriver\lib\gecko.js:205:5)
[debug] [AppiumDriver@20f2]     at GeckoDriver.createSession (C:\Users\USER\.appium\node_modules\appium-geckodriver\lib\driver.js:58:7)
[debug] [AppiumDriver@20f2]     at AppiumDriver.createSession (C:\Users\USER\AppData\Roaming\nvm\v18.14.2\node_modules\appium\lib\appium.js:349:35)
[HTTP] <-- POST /session 500 48605 ms - 1369
whimboo commented 1 year ago

Could you please attach the adb logcat which was created while running the above snippet? It would be needed given that we don't seem to be able to include error details. Thanks.

AlexandraMoga commented 1 year ago

@whimboo this is the output from adb logcat when trying to start a session with the configuration mentioned:

03-01 12:30:20.181   524  1026 I ActivityManager: Force stopping org.mozilla.fenix appid=10122 user=0: clear data
03-01 12:30:20.184   524   553 I ActivityManager: Force stopping org.mozilla.fenix appid=10122 user=-1: clearApplicationUserData
03-01 12:30:20.185  1392  1436 I MediaProvider: Invalidating LocalCallingIdentity cache for package org.mozilla.fenix. Reason: op android:read_external_storage
03-01 12:30:20.193   427   427 I keystore: clear_uid 10122
03-01 12:30:20.196 11065 11067 I cmd     : oneway function results will be dropped but finished with status OK and parcel size 4
03-01 12:30:20.200   677   677 V AvrcpMediaPlayerList: mPackageChangedBroadcastReceiver: action: android.intent.action.PACKAGE_DATA_CLEARED
03-01 12:30:20.200  1196  1196 I GeofencerStateMachine: removeGeofences: removeRequest=RemoveGeofencingRequest[REMOVE_ALL packageName=org.mozilla.fenix]
03-01 12:30:20.200   524   552 E system_server: No package ID 7f found for ID 0x7f080169.
03-01 12:30:20.200   524   552 E system_server: No package ID 7f found for ID 0x7f1201df.
03-01 12:30:20.200   524   552 E system_server: No package ID 7f found for ID 0x7f1201df.
03-01 12:30:20.200   524   552 E system_server: No package ID 7f found for ID 0x7f080167.
03-01 12:30:20.200   524   552 E system_server: No package ID 7f found for ID 0x7f1201de.
03-01 12:30:20.200   524   552 E system_server: No package ID 7f found for ID 0x7f1201de.
03-01 12:30:20.203   932   932 D CarrierSvcBindHelper: No carrier app for: 0
03-01 12:30:20.224  1392  2566 I MediaProvider: Begin Intent { act=android.intent.action.PACKAGE_DATA_CLEARED dat=package:org.mozilla.fenix flg=0x1000010 cmp=com.android.providers.media.module/com.android.providers.media.MediaService (has extras) }
03-01 12:30:20.229  1392  2566 I MediaProvider: End Intent { act=android.intent.action.PACKAGE_DATA_CLEARED dat=package:org.mozilla.fenix flg=0x1000010 cmp=com.android.providers.media.module/com.android.providers.media.MediaService (has extras) }
03-01 12:30:20.231  1196 11071 I Fitness : FitCleanupIntentOperation received Intent android.intent.action.PACKAGE_DATA_CLEARED [CONTEXT service_id=17 ]
03-01 12:30:20.232   524   558 E libprocessgroup: AddTidToCgroup failed to write '11074'; fd=66: Invalid argument
03-01 12:30:20.232   524   558 E libprocessgroup: Failed to add task into cgroup
03-01 12:30:20.232   524   558 W libprocessgroup: ExecuteForTask failed for aggregate profile: Invalid argument
03-01 12:30:20.242  1530  8226 I Icing   : doRemovePackageData org.mozilla.fenix [CONTEXT service_id=21 ]
03-01 12:30:22.268  1392  1424 I MediaProvider: Invalidating LocalCallingIdentity cache for package org.mozilla.fenix. Reason: op android:read_external_storage
03-01 12:30:22.443   524  1026 D WifiNl80211Manager: Scan result ready event
03-01 12:30:22.443   524  1026 D WifiNative: Scan result ready event
03-01 12:30:40.914   386   386 I /apex/com.android.adbd/bin/adbd: type=1400 audit(0.0:2518): avc: denied { search } for comm=73796E6320737663203631 name="oem" dev="dm-4" ino=42 scontext=u:r:adbd:s0 tcontext=u:object_r:oemfs:s0 tclass=dir permissive=1
03-01 12:30:43.022 11108 11110 I cmd     : oneway function results will be dropped but finished with status OK and parcel size 4
whimboo commented 1 year ago

This is only an excerpt given that it misses all the geckodriver log output. Can you repeat again but start geckodriver with the -vv option? This will enable trace logs which hopefully give more information.

AlexandraMoga commented 1 year ago

@whimboo These are the captured logs when running geckodriver with log level trace: geckodriver-appium.txt

whimboo commented 1 year ago

Hm, this log is really strange. The last successful command that I can see is that geckodriver tries to set the permissions for the Firefox profile to 777 but then something failed and we clean-up the device. Strangely I cannot see the command that failed here. 

[debug] [GeckoDriver@03b7 (1d39ac55)] [geckodriver.exe] 1677837573945   mozdevice       TRACE   execute_host_command: >> "host:transport:emulator-5554"
[debug] [GeckoDriver@03b7 (1d39ac55)] [geckodriver.exe] 1677837573945   mozdevice       TRACE   execute_host_command: << []
[debug] [GeckoDriver@03b7 (1d39ac55)] 1677837573945     mozdevice       TRACE   execute_host_command: >> "shell:su 0 chmod  -R 777 /sdcard/Android/data/org.mozilla.fenix/files/test_root/org.mozilla.fenix-geckodriver-profile"
[debug] [GeckoDriver@03b7 (1d39ac55)] [geckodriver.exe] 1677837573968   mozdevice       TRACE   execute_host_command: << ""
[debug] [GeckoDriver@03b7 (1d39ac55)] [geckodriver.exe] 1677837578107   mozdevice       TRACE   execute_host_command: >> "host:transport:emulator-5554"
[debug] [GeckoDriver@03b7 (1d39ac55)] [geckodriver.exe] 1677837578108   mozdevice       TRACE   execute_host_command: << []
[debug] [GeckoDriver@03b7 (1d39ac55)] 1677837578108     mozdevice       TRACE   execute_host_command: >> "shell:su 0 am clear-debug-app org.mozilla.fenix"
[debug] [GeckoDriver@03b7 (1d39ac55)] [geckodriver.exe] 1677837578162   mozdevice       TRACE   execute_host_command: << ""

Could you please also attach the corresponding adb logcat with not removing too much content? Thanks.

AlexandraMoga commented 1 year ago

Sorry @whimboo but I'm not seeing any geckodriver logs in the adb logcat output generated when I'm running my script: adb logcat.txt

whimboo commented 1 year ago

Sorry for dropping the ball on this issue. Is that still a problem with the recent versions of Firefox and geckodriver?

ethanyou725 commented 1 week ago

yes, still have the same issue.

[GeckoDriver@b65a] Creating session with W3C capabilities: {
[GeckoDriver@b65a]   "alwaysMatch": {
[GeckoDriver@b65a]     "browserName": "MozillaFirefox",
[GeckoDriver@b65a]     "platformName": "Mac",
[GeckoDriver@b65a]     "moz:firefoxOptions": {
[GeckoDriver@b65a]       "androidPackage": "org.mozilla.firefox",
[GeckoDriver@b65a]       "log": {
[GeckoDriver@b65a]         "level": "trace"
[GeckoDriver@b65a]       }
[GeckoDriver@b65a]     },
[GeckoDriver@b65a]     "appium:automationName": "Gecko",
[GeckoDriver@b65a]     "appium:verbosity": "debug",
[GeckoDriver@b65a]     "appium:newCommandTimeout": 3600,
[GeckoDriver@b65a]     "appium:connectHardwareKeyboard": true
[GeckoDriver@b65a]   },
[GeckoDriver@b65a]   "firstMatch": [
[GeckoDriver@b65a]     {}
[GeckoDriver@b65a]   ]
[GeckoDriver@b65a] }
[GeckoDriver@b65a] The following provided capabilities were not recognized by this driver:
[GeckoDriver@b65a]   connectHardwareKeyboard
[GeckoDriver@b65a (db891f60)] Session created with session id: db891f60-5996-489c-ae6a-491b48c90038
[GeckoDriver@b65a (db891f60)] Starting '/opt/homebrew/bin/geckodriver' with args ["-v","-p","5200"]
[GeckoDriver@b65a (db891f60)] Matched '/status' to command name 'getStatus'
[GeckoDriver@b65a (db891f60)] Proxying [GET /status] to [GET http://127.0.0.1:5200/status] with no body
[GeckoDriver@b65a (db891f60)] connect ECONNREFUSED 127.0.0.1:5200
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390537408   geckodriver INFO    Listening on 127.0.0.1:5200
[GeckoDriver@b65a (db891f60)] Matched '/status' to command name 'getStatus'
[GeckoDriver@b65a (db891f60)] Proxying [GET /status] to [GET http://127.0.0.1:5200/status] with no body
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538452   webdriver::server   DEBUG   -> GET /status
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538453   webdriver::server   DEBUG   <- 200 OK {"value":{"message":"","ready":true}}
[GeckoDriver@b65a (db891f60)] Got response with status 200: {"value":{"message":"","ready":true}}
[GeckoDriver@b65a (db891f60)] Matched '/session' to command name 'createSession'
[GeckoDriver@b65a (db891f60)] Proxying [POST /session] to [POST http://127.0.0.1:5200/session] with body: {"capabilities":{"firstMatch":[{}],"alwaysMatch":{"browserName":"firefox","platformName":"mac","moz:firefoxOptions":{"androidPackage":"org.mozilla.firefox","log":{"level":"trace"}}}}}
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538462   webdriver::server   DEBUG   -> POST /session {"capabilities":{"firstMatch":[{}],"alwaysMatch":{"browserName":"firefox","platformName":"mac","moz:firefoxOptions":{"androidPackage":"org.mozilla.firefox","log":{"level":"trace"}}}}}
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538471   mozdevice   TRACE   adb server response was "RFCX401L41P            device 0-1 product:e1qzcx model:SM_S9210 device:e1q transport_id:11\n"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538471   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] 1719390538472 mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538472 mozdevice   TRACE   execute_host_command: >> "shell:id"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538529   mozdevice   TRACE   execute_host_command: << "uid=2000(shell) gid=2000(shell) groups=2000(shell),1004(input),1007(log),1011(adb),1015(sdcard_rw), ... (net_bt_admin),3002(net_bt),3003(inet),3006(net_bw_stats),3009(readproc),3011(uhid),3012(readtracefs) context=u:r:shell:s0\n"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538530   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538530   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538530 mozdevice   TRACE   execute_host_command: >> "shell:su 0 id"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538562   mozdevice   TRACE   execute_host_command: << "/system/bin/sh: su: inaccessible or not found\n"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538563   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] 1719390538563 mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538563 mozdevice   TRACE   execute_host_command: >> "shell:su -c id"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538600   mozdevice   TRACE   execute_host_command: << "/system/bin/sh: su: inaccessible or not found\n"
[GeckoDriver@b65a (db891f60)] 1719390538600 mozdevice   INFO    Device is unrooted
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538601   geckodriver::android    DEBUG   Marionette port forward (53866 -> 2829) started
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538602   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538602   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538602 mozdevice   TRACE   execute_host_command: >> "shell:echo $EXTERNAL_STORAGE"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538640   mozdevice   TRACE   execute_host_command: << "/sdcard\n"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538640   geckodriver::android    DEBUG   Connecting: options=AndroidOptions { activity: Some("org.mozilla.fenix.IntentReceiverActivity"), device_serial: None, intent_ ... ox", storage: Auto }, storage=Sdcard) test_root=/sdcard/Android/data/org.mozilla.firefox/files/test_root, run_as_package=None
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538641   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] 1719390538641 mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538641 mozdevice   TRACE   execute_host_command: >> "shell:pm list packages org.mozilla.firefox"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538724   mozdevice   TRACE   execute_host_command: << "package:org.mozilla.firefox\n"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538735   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538735   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538736 mozdevice   TRACE   execute_host_command: >> "shell:pm clear org.mozilla.firefox"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538913   mozdevice   TRACE   execute_host_command: << "Success\n"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538914   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538914   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538914 mozdevice   TRACE   execute_host_command: >> "shell:pm grant org.mozilla.firefox android.permission.READ_EXTERNAL_STORAGE"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538960   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538962   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390538962   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390538962 mozdevice   TRACE   execute_host_command: >> "shell:pm grant org.mozilla.firefox android.permission.WRITE_EXTERNAL_STORAGE"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539025   mozdevice   TRACE   execute_host_command: << "\nException occurred while executing 'grant':\njava.lang.SecurityException: Package org.mozilla.fir ... 097)\n\tat android.os.Binder.execTransactInternal(Binder.java:1380)\n\tat android.os.Binder.execTransact(Binder.java:1311)\n"
[GeckoDriver@b65a (db891f60)] 1719390539025 mozdevice   DEBUG   Creating /sdcard/Android/data/org.mozilla.firefox/files/test_root
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539026   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539027   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539027 mozdevice   TRACE   execute_host_command: >> "shell:mkdir -p /sdcard/Android/data/org.mozilla.firefox/files/test_root"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539059   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539061   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539061   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539061 mozdevice   TRACE   execute_host_command: >> "shell:chmod  -R 777 /sdcard/Android/data/org.mozilla.firefox/files/test_root"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539100   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] 1719390539100 mozdevice   DEBUG   Deleting /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539101   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] 1719390539101 mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539101 mozdevice   TRACE   execute_host_command: >> "shell:rm -rf /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539137   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539137   mozdevice   DEBUG   Pushing /var/folders/mb/_cv3vxkj74q4m63bz2twb0zh0000gn/T/rust_mozprofileecmumq to /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539139   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539139   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539139   mozdevice   TRACE   execute_host_command: >> "shell:ls /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539180   mozdevice   TRACE   execute_host_command: << "ls: /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile: No such file or directory\n"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539181   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539181   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539181 mozdevice   TRACE   execute_host_command: >> "shell:ls /sdcard/Android/data/org.mozilla.firefox/files/test_root"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539217   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] 1719390539217 mozdevice   DEBUG   Creating /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539218   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539218   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539218 mozdevice   TRACE   execute_host_command: >> "shell:mkdir -p /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539262   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539264   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539264   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539264 mozdevice   TRACE   execute_host_command: >> "shell:chmod  -R 777 /sdcard/Android/data/org.mozilla.firefox/files/test_root/org.mozilla.firefox-geckodriver-profile"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539298   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539310   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539310   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539310 mozdevice   TRACE   execute_host_command: >> "shell:am clear-debug-app org.mozilla.firefox"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539397   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539397   geckodriver::android    DEBUG   Disabled reading from configuration file
[GeckoDriver@b65a (db891f60)] 1719390539397 mozdevice   DEBUG   Deleting /data/local/tmp/org.mozilla.firefox-geckoview-config.yaml
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539409   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539409   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539409 mozdevice   TRACE   execute_host_command: >> "shell:rm -rf /data/local/tmp/org.mozilla.firefox-geckoview-config.yaml"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539463   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539463   geckodriver::android    DEBUG   Deleted GeckoView configuration file
[GeckoDriver@b65a (db891f60)] 1719390539463 mozdevice   DEBUG   Deleting /sdcard/Android/data/org.mozilla.firefox/files/test_root
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539467   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539468   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539468 mozdevice   TRACE   execute_host_command: >> "shell:rm -rf /sdcard/Android/data/org.mozilla.firefox/files/test_root"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539517   mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539517   geckodriver::android    DEBUG   Deleted test root folder: /sdcard/Android/data/org.mozilla.firefox/files/test_root
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539518   mozdevice   TRACE   execute_host_command: >> "host:transport:RFCX401L41P"
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539519   mozdevice   TRACE   execute_host_command: << []
[GeckoDriver@b65a (db891f60)] 1719390539519 mozdevice   TRACE   execute_host_command: >> "host-serial:RFCX401L41P:killforward:tcp:53866"
[GeckoDriver@b65a (db891f60)] 1719390539519 mozdevice   TRACE   execute_host_command: << ""
[GeckoDriver@b65a (db891f60)] 1719390539519 geckodriver::android    DEBUG   Marionette port forward (53866 -> 2829) stopped
[GeckoDriver@b65a (db891f60)] [geckodriver] 1719390539519   webdriver::server   DEBUG   <- 500 Internal Server Error {"value":{"error":"unknown error","message":"adb error: fchown failed: Operation not permitted","stacktrace":""}}
[GeckoDriver@b65a (db891f60)] Got response with status 500: {"value":{"error":"unknown error","message":"adb error: fchown failed: Operation not permitted","stacktrace":""}}
[W3C] Matched W3C error code 'unknown error' to UnknownError
[GeckoDriver@b65a (db891f60)] Ending Gecko Driver session
[GeckoDriver@b65a (db891f60)] geckodriver has exited with code null, signal SIGTERM
[AppiumDriver@3bc1] Event 'newSessionStarted' logged at 1719390539530 (16:28:59 GMT+0800 (China Standard Time))
[AppiumDriver@3bc1] Encountered internal error running command: UnknownError: An unknown server-side error occurred while processing the command. Original error: adb error: fchown failed: Operation not permitted
[AppiumDriver@3bc1]     at errorFromW3CJsonCode (/usr/local/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:1112:25)
[AppiumDriver@3bc1]     at ProxyRequestError.getActualError (/usr/local/lib/node_modules/appium/node_modules/@appium/base-driver/lib/protocol/errors.js:981:14)
[AppiumDriver@3bc1]     at GeckoProxy.command (/usr/local/lib/node_modules/appium/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:353:19)
[AppiumDriver@3bc1]     at processTicksAndRejections (node:internal/process/task_queues:95:5)
[AppiumDriver@3bc1]     at GeckoDriverServer.start (/Users/zackyou/.appium/node_modules/appium-geckodriver/lib/gecko.js:227:5)
[AppiumDriver@3bc1]     at GeckoDriver.createSession (/Users/zackyou/.appium/node_modules/appium-geckodriver/lib/driver.js:65:7)
[AppiumDriver@3bc1]     at AppiumDriver.createSession (/usr/local/lib/node_modules/appium/lib/appium.js:717:35)
[HTTP] <-- POST /session 500 2169 ms - 1131

Sorry for dropping the ball on this issue. Is that still a problem with the recent versions of Firefox and geckodriver?

whimboo commented 1 week ago

@ethanyou725 your issue is a bit different. Maybe you can just comment on issue #1885 (no trace log needed) and mention which kind of phone and Android version you are running? Thanks.