Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Android 14 Beta 5 stuck in "Preparing" step in STF #692

Open
T0n3l opened this issue Aug 16, 2023 · 17 comments
Open

Android 14 Beta 5 stuck in "Preparing" step in STF #692

T0n3l opened this issue Aug 16, 2023 · 17 comments

Comments

@T0n3l
Copy link

T0n3l commented Aug 16, 2023

I am using docker image for devicefarmer/stf:3.6.5 (link here -> https://hub.docker.com/layers/devicefarmer/stf/3.6.5/images/sha256-2101f29fc71c8cf7db6fab805b570a286ba7932cc1fbfe977ec2d42512c1e2fe?context=explore) and after plugging a device with Android 14 Beta 5 (Google Pixel 6) it can be controlled via adb on the machine, but it is stuck in "Preparing" state in STF.

@T0n3l T0n3l changed the title Android 14 Beta 5 not visible in STF Android 14 Beta 5 stuck in "Preparing" step in STF Aug 16, 2023
@sn00wden
Copy link

@T0n3l You should compile latest STFService.apk from https://github.com/DeviceFarmer/STFService.apk and replace itto your STF in /app/vendor/STFService/ folder.
Also probably you should utick at Device in Developer Options: Verify Apps via USB and Verify bytecode of debuggable apps.

@T0n3l
Copy link
Author

T0n3l commented Aug 16, 2023

@cert-x on device is installed the apk with version 2.4.10. is there any new version of the apk?
thank you!

@T0n3l
Copy link
Author

T0n3l commented Aug 16, 2023

looking up in the logs, I found the following stacktrace:

E AndroidRuntime: java.lang.UnsupportedOperationException: WindowManagerEventInjector is not supported E AndroidRuntime: at jp.co.cyberagent.stf.compat.InputManagerWrapper$WindowManagerEventInjector.<init>(InputManagerWrapper.java:97) E AndroidRuntime: at jp.co.cyberagent.stf.compat.InputManagerWrapper.<init>(InputManagerWrapper.java:19) E AndroidRuntime: at jp.co.cyberagent.stf.MinitouchAgent.<init>(MinitouchAgent.java:272) E AndroidRuntime: at jp.co.cyberagent.stf.Agent.main(Agent.java:65) E AndroidRuntime: at com.android.internal.os.RuntimeInit.nativeFinishInit(Native Method) E AndroidRuntime: at com.android.internal.os.RuntimeInit.main(RuntimeInit.java:359)

@gadgadskiy
Copy link

hi, guys. I've updated the apk as you described above, but still get an error. I use container devicefarmer/stf:latest
this log appears in a loop with the fatal error at the end

2023-08-16T13:49:30.792Z INF/provider 7 [*] Cleaning up device worker "<my_device_udid>"
2023-08-16T13:49:30.792Z ERR/provider 7 [*] Device worker "<my_device_udid>" died with code 1
2023-08-16T13:49:30.792Z INF/provider 7 [*] Restarting device worker "<my_device_udid>"
2023-08-16T13:49:31.514Z INF/device:support:push 371 [<my_device_udid>] Sending output to "tcp://stf.company.com:7116"
2023-08-16T13:49:31.518Z INF/device 371 [<my_device_udid>] Preparing device
2023-08-16T13:49:31.839Z INF/device:support:sub 371 [<my_device_udid>] Receiving input from "tcp://stf.company.com:7114"
2023-08-16T13:49:31.841Z INF/device:support:sub 371 [<my_device_udid>] Subscribing to permanent channel "*ALL"
2023-08-16T13:49:31.885Z INF/device:support:properties 371 [<my_device_udid>] Loading properties
2023-08-16T13:49:31.917Z INF/device:support:sdk 371 [<my_device_udid>] Supports SDK 34
2023-08-16T13:49:31.919Z INF/device:support:abi 371 [<my_device_udid>] Supports ABIs arm64-v8a, armeabi-v7a, armeabi
2023-08-16T13:49:32.086Z INF/device:resources:minicap 371 [<my_device_udid>] Installing "/app/node_modules/@devicefarmer/minicap-prebuilt/prebuilt/noarch/minicap.apk" as "/data/local/tmp/minicap.apk"
2023-08-16T13:49:32.307Z INF/device:resources:service 371 [<my_device_udid>] Checking whether we need to install STFService
2023-08-16T13:49:32.360Z INF/device:resources:service 371 [<my_device_udid>] Running version check
2023-08-16T13:49:33.383Z INF/device:resources:service 371 [<my_device_udid>] STFService up to date
2023-08-16T13:49:33.385Z INF/device:plugins:service 371 [<my_device_udid>] Launching agent
2023-08-16T13:49:33.786Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "Starting minitouch agent"
2023-08-16T13:49:33.789Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "java.lang.NoSuchMethodException: android.view.IWindowManager$Stub$Proxy.injectKeyEvent [class android.view.KeyEvent, boolean]"
2023-08-16T13:49:33.790Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at java.lang.Class.getMethod(Class.java:2937)"
2023-08-16T13:49:33.791Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at java.lang.Class.getMethod(Class.java:2449)"
2023-08-16T13:49:33.792Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.compat.InputManagerWrapper$WindowManagerEventInjector.<init>(InputManagerWrapper.java:93)"
2023-08-16T13:49:33.792Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.compat.InputManagerWrapper.<init>(InputManagerWrapper.java:19)"
2023-08-16T13:49:33.793Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.MinitouchAgent.<init>(MinitouchAgent.java:288)"
2023-08-16T13:49:33.793Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.Agent.main(Agent.java:65)"
2023-08-16T13:49:33.794Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at com.android.internal.os.RuntimeInit.nativeFinishInit(Native Method)"
2023-08-16T13:49:33.794Z INF/device:plugins:service 371 [<my_device_udid>] Agent says: "at com.android.internal.os.RuntimeInit.main(RuntimeInit.java:359)"
2023-08-16T13:49:34.521Z INF/provider 7 [*] Providing 0 of 1 device(s); waiting for "<my_device_udid>"
2023-08-16T13:49:43.612Z FTL/device 371 [<my_device_udid>] Setup had an error TimeoutError: operation timed out
    at afterTimeout (/app/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:11:15)
    at Timeout.timeoutTimeout [as _onTimeout] (/app/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:53:9)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7)
2023-08-16T13:49:43.613Z FTL/util:lifecycle 371 [<my_device_udid>] Shutting down due to fatal error
2023-08-16T13:49:43.622Z INF/provider 7 [*] Cleaning up device worker "<my_device_udid>"
2023-08-16T13:49:43.622Z ERR/provider 7 [*] Device worker "<my_device_udid>" died with code 1
2023-08-16T13:49:43.622Z INF/provider 7 [*] Restarting device worker "<my_device_udid>"
2023-08-16T13:49:44.355Z INF/device:support:push 384 [<my_device_udid>] Sending output to "tcp://stf.company.com:7116"
2023-08-16T13:49:44.359Z INF/device 384 [<my_device_udid>] Preparing device
2023-08-16T13:49:44.522Z INF/provider 7 [*] Providing 0 of 1 device(s); waiting for "<my_device_udid>"
2023-08-16T13:49:44.685Z INF/device:support:sub 384 [<my_device_udid>] Receiving input from "tcp://stf.company.com:7114"
2023-08-16T13:49:44.686Z INF/device:support:sub 384 [<my_device_udid>] Subscribing to permanent channel "*ALL"
2023-08-16T13:49:44.727Z INF/device:support:properties 384 [<my_device_udid>] Loading properties
2023-08-16T13:49:44.758Z INF/device:support:sdk 384 [<my_device_udid>] Supports SDK 34
2023-08-16T13:49:44.759Z INF/device:support:abi 384 [<my_device_udid>] Supports ABIs arm64-v8a, armeabi-v7a, armeabi
2023-08-16T13:49:44.914Z INF/device:resources:minicap 384 [<my_device_udid>] Installing "/app/node_modules/@devicefarmer/minicap-prebuilt/prebuilt/noarch/minicap.apk" as "/data/local/tmp/minicap.apk"
2023-08-16T13:49:45.100Z INF/device:resources:service 384 [<my_device_udid>] Checking whether we need to install STFService
2023-08-16T13:49:45.134Z INF/device:resources:service 384 [<my_device_udid>] Running version check
2023-08-16T13:49:46.166Z INF/device:resources:service 384 [<my_device_udid>] STFService up to date
2023-08-16T13:49:46.167Z INF/device:plugins:service 384 [<my_device_udid>] Launching agent
2023-08-16T13:49:46.520Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "Starting minitouch agent"
2023-08-16T13:49:46.539Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "java.lang.NoSuchMethodException: android.view.IWindowManager$Stub$Proxy.injectKeyEvent [class android.view.KeyEvent, boolean]"
2023-08-16T13:49:46.541Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at java.lang.Class.getMethod(Class.java:2937)"
2023-08-16T13:49:46.543Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at java.lang.Class.getMethod(Class.java:2449)"
2023-08-16T13:49:46.545Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.compat.InputManagerWrapper$WindowManagerEventInjector.<init>(InputManagerWrapper.java:93)"
2023-08-16T13:49:46.547Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.compat.InputManagerWrapper.<init>(InputManagerWrapper.java:19)"
2023-08-16T13:49:46.548Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.MinitouchAgent.<init>(MinitouchAgent.java:288)"
2023-08-16T13:49:46.548Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at jp.co.cyberagent.stf.Agent.main(Agent.java:65)"
2023-08-16T13:49:46.549Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at com.android.internal.os.RuntimeInit.nativeFinishInit(Native Method)"
2023-08-16T13:49:46.550Z INF/device:plugins:service 384 [<my_device_udid>] Agent says: "at com.android.internal.os.RuntimeInit.main(RuntimeInit.java:359)"
2023-08-16T13:49:54.529Z INF/provider 7 [*] Providing 0 of 1 device(s); waiting for "<my_device_udid>"
2023-08-16T13:49:56.342Z FTL/device 384 [<my_device_udid>] Setup had an error TimeoutError: operation timed out
    at afterTimeout (/app/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:11:15)
    at Timeout.timeoutTimeout [as _onTimeout] (/app/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:53:9)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7)
2023-08-16T13:49:56.343Z FTL/util:lifecycle 384 [<my_device_udid>] Shutting down due to fatal error

@sn00wden
Copy link

Do you have latest adbd?

@gadgadskiy
Copy link

I cannot locate abdb inside my infrastructure. Can you clarify where it should be?

@sn00wden
Copy link

@gadgadskiy from the DEPLOYMENT.MD adbd.service

@gadgadskiy
Copy link

@cert-x, we don't have it at all because we use a separate container for each device (and stf client container calls adb from them).
The adb version is 34.0.1

@T0n3l
Copy link
Author

T0n3l commented Aug 17, 2023

@cert-x I think the app is crashing on the Android device considering the logs I posted yesterday

@sn00wden
Copy link

sn00wden commented Aug 17, 2023

@T0n3l Do other devices work properly with Android 14 beta 5? - If yes, do issue mostly connected to this device.
@gadgadskiy my adbd -v is 34.0.3 Was STFservice.apk installed at the device? Have you tried to restart docker after device is connected?

@T0n3l
Copy link
Author

T0n3l commented Aug 17, 2023

@cert-x This is the only device I have that accepts Android 14 Beta. Unfortunately, I am not able to test with other device.

@gadgadskiy
Copy link

@cert-x, yes, I updated the apk and restarted both containers but still got the same error in all cases.
Unfortunately, I have only one device compatible with 14 Beta (Pixel 5) as well. Before updating, STF worked on it well.

@T0n3l
Copy link
Author

T0n3l commented Aug 22, 2023

@cert-x My problem was fixed after upgrading stf apk to version 12. Thank you!

@pisanyialeksei
Copy link

Replacing the APK helped.
Example of path on linux machine: /usr/local/lib/node_modules/@devicefarmer/stf/vendor/STFService

@kimikorento-o
Copy link

Latest dockerhub image that contains the v2.4.12 apk file did not solve the issue with Android 14 QPR2 Beta Program, Pixel 7. Same device works when using latest public android 14 version with latest stf release v3.6.6, but when beta program is opted in, the device gets stuck at preparing phase (reproduced twice) with the following logs:

2024-01-24T10:58:01.163Z INF/device:resources:service 446 [<serial>] STFService up to date
2024-01-24T10:58:01.165Z INF/device:plugins:service 446 [<serial>] Launching agent
2024-01-24T10:58:01.756Z INF/device:plugins:service 446 [<serial>] Agent says: "Starting minitouch agent"
2024-01-24T10:58:10.624Z INF/provider 43 [*] Providing 1 of 2 device(s); waiting for "<serial>"
2024-01-24T10:58:11.559Z FTL/device 446 [<serial>] Setup had an error TimeoutError: operation timed out
    at afterTimeout (/app/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:11:15)
    at Timeout.timeoutTimeout [as _onTimeout] (/app/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:53:9)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7)
2024-01-24T10:58:11.561Z FTL/util:lifecycle 446 [<serial>] Shutting down due to fatal error
2024-01-24T10:58:11.573Z INF/provider 43 [*] Cleaning up device worker "<serial>"
2024-01-24T10:58:11.573Z ERR/provider 43 [*] Device worker "<serial>" died with code 1
2024-01-24T10:58:11.573Z INF/provider 43 [*] Restarting device worker "<serial>"
...

@KingRat0011
Copy link

My devices are Pixels running Android 14, I seem to have the same problem, stf was build with npm, install

xxx:bin $ ./stf --version
3.6.6
xxx:bin $ ./stf doctor
2024-02-29T05:28:22.613Z INF/cli:doctor 17242 [*] OS Arch: x64
2024-02-29T05:28:22.614Z INF/cli:doctor 17242 [*] OS Platform: linux
2024-02-29T05:28:22.615Z INF/cli:doctor 17242 [*] OS Platform: 3.10.0-1160.95.1.el7.x86_64
2024-02-29T05:28:22.615Z INF/cli:doctor 17242 [*] Using Node 14.21.3
2024-02-29T05:28:22.627Z INF/cli:doctor 17242 [*] Using ZeroMQ 4.2.2
2024-02-29T05:28:22.640Z INF/cli:doctor 17242 [*] Using ADB 1.0.31
2024-02-29T05:28:22.640Z INF/cli:doctor 17242 [*] Using RethinkDB 2.4.2
2024-02-29T05:28:22.645Z INF/cli:doctor 17242 [*] Using ProtoBuf 3.14.0
2024-02-29T05:28:22.653Z INF/cli:doctor 17242 [*] Using GraphicsMagick 1.3.38
xxx:bin $
xxx:bin $ node -v
v14.21.3
xxx:bin $

2024-02-29T05:27:16.190Z INF/device:plugins:service 14645 [2B211JEHN08476] Agent says: "Starting minitouch agent"
2024-02-29T05:27:25.974Z FTL/device 14645 [2B211JEHN08476] Setup had an error TimeoutError: operation timed out
    at afterTimeout (/usr/lib/node_modules/stf/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:11:15)
    at Timeout.timeoutTimeout [as _onTimeout] (/usr/lib/node_modules/stf/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:53:9)
    at listOnTimeout (internal/timers.js:557:17)
    at processTimers (internal/timers.js:500:7)
2024-02-29T05:27:25.975Z FTL/util:lifecycle 14645 [2B211JEHN08476] Shutting down due to fatal error
2024-02-29T05:27:25.986Z INF/provider 12570 [*] Cleaning up device worker "2B211JEHN08476"
2024-02-29T05:27:25.986Z ERR/provider 12570 [*] Device worker "2B211JEHN08476" died with code 1
2024-02-29T05:27:25.986Z INF/provider 12570 [*] Restarting device worker "2B211JEHN08476"
2024-02-29T05:27:26.697Z INF/device:support:push 15049 [2B211JEHN08476] Sending output to "tcp://127.0.0.1:7116"
2024-02-29T05:27:26.699Z INF/device 15049 [2B211JEHN08476] Preparing device
2024-02-29T05:27:27.002Z INF/device:support:sub 15049 [2B211JEHN08476] Receiving input from "tcp://127.0.0.1:7114"
2024-02-29T05:27:27.003Z INF/device:support:sub 15049 [2B211JEHN08476] Subscribing to permanent channel "*ALL"
2024-02-29T05:27:27.097Z INF/device:support:properties 15049 [2B211JEHN08476] Loading properties
2024-02-29T05:27:27.193Z INF/device:support:sdk 15049 [2B211JEHN08476] Supports SDK 34
2024-02-29T05:27:27.194Z INF/device:support:abi 15049 [2B211JEHN08476] Supports ABIs arm64-v8a
2024-02-29T05:27:27.514Z INF/device:resources:minicap 15049 [2B211JEHN08476] Installing "/usr/lib/node_modules/stf/node_modules/@devicefarmer/minicap-prebuilt/prebuilt/noarch/minicap.apk" as "/data/local/tmp/minicap.apk"
2024-02-29T05:27:28.003Z INF/device:resources:service 15049 [2B211JEHN08476] Checking whether we need to install STFService
2024-02-29T05:27:28.107Z INF/device:resources:service 15049 [2B211JEHN08476] Running version check
2024-02-29T05:27:29.204Z INF/device:resources:service 15049 [2B211JEHN08476] STFService up to date
2024-02-29T05:27:29.205Z INF/device:plugins:service 15049 [2B211JEHN08476] Launching agent
2024-02-29T05:27:30.028Z INF/device:plugins:service 15049 [2B211JEHN08476] Agent says: "Starting minitouch agent"
2024-02-29T05:27:39.811Z FTL/device 15049 [2B211JEHN08476] Setup had an error TimeoutError: operation timed out
    at afterTimeout (/usr/lib/node_modules/stf/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:11:15)
    at Timeout.timeoutTimeout [as _onTimeout] (/usr/lib/node_modules/stf/node_modules/@devicefarmer/adbkit/node_modules/bluebird/js/main/timers.js:53:9)
    at listOnTimeout (internal/timers.js:557:17)
    at processTimers (internal/timers.js:500:7)
2024-02-29T05:27:39.812Z FTL/util:lifecycle 15049 [2B211JEHN08476] Shutting down due to fatal error
2024-02-29T05:27:39.820Z INF/provider 12570 [*] Cleaning up device worker "2B211JEHN08476"
2024-02-29T05:27:39.820Z ERR/provider 12570 [*] Device worker "2B211JEHN08476" died with code 1
2024-02-29T05:27:39.820Z INF/provider 12570 [*] Restarting device worker "2B211JEHN08476"
2024-02-29T05:27:40.536Z INF/device:support:push 15130 [2B211JEHN08476] Sending output to "tcp://127.0.0.1:7116"
2024-02-29T05:27:40.538Z INF/device 15130 [2B211JEHN08476] Preparing device
2024-02-29T05:27:40.850Z INF/device:support:sub 15130 [2B211JEHN08476] Receiving input from "tcp://127.0.0.1:7114"
2024-02-29T05:27:40.850Z INF/device:support:sub 15130 [2B211JEHN08476] Subscribing to permanent channel "*ALL"
2024-02-29T05:27:40.942Z INF/device:support:properties 15130 [2B211JEHN08476] Loading properties
2024-02-29T05:27:41.036Z INF/device:support:sdk 15130 [2B211JEHN08476] Supports SDK 34
2024-02-29T05:27:41.037Z INF/device:support:abi 15130 [2B211JEHN08476] Supports ABIs arm64-v8a
2024-02-29T05:27:41.438Z INF/device:resources:minicap 15130 [2B211JEHN08476] Installing "/usr/lib/node_modules/stf/node_modules/@devicefarmer/minicap-prebuilt/prebuilt/noarch/minicap.apk" as "/data/local/tmp/minicap.apk"
2024-02-29T05:27:41.930Z INF/device:resources:service 15130 [2B211JEHN08476] Checking whether we need to install STFService
2024-02-29T05:27:42.045Z INF/device:resources:service 15130 [2B211JEHN08476] Running version check
2024-02-29T05:27:43.138Z INF/device:resources:service 15130 [2B211JEHN08476] STFService up to date
2024-02-29T05:27:43.139Z INF/device:plugins:service 15130 [2B211JEHN08476] Launching agent
2024-02-29T05:27:43.932Z INF/device:plugins:service 15130 [2B211JEHN08476] Agent says: "Starting minitouch agent"
^C

I see STFService.apk has been mentioned being the problem, is there any way to check what version I'm running?

xxx:vendor $ cd STFService/
xxx:STFService $ ls -ltr
total 1352
-rw-rw-r--. 1 xxx xxx    6192 Feb 26 23:29 wire.proto
-rw-rw-r--. 1 xxx xxx 1372211 Feb 26 23:29 STFService.apk
xxx:STFService $ pwd
/usr/lib/node_modules/stf/vendor/STFService
xxx:STFService $ 

@kimikorento-o
Copy link

The root reason for my case seems to be DeviceFarmer/STFService.apk#130. Same logcat error seen with pixel 7 after march update, as with pixel 7 beta previously. Tested with STFService.apk 2.5.0 and 2.4.11 by installing release package via adb and running it with adb shell am start-foreground-service --user 0 -a jp.co.cyberagent.stf.ACTION_START -n [jp.co.cyberagent.stf/.Service](http://jp.co.cyberagent.stf/.Service)
image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants