search

rajdeepv / Appium-Jetpack-Compose

2 stars 0 forks source link

Appium Server gets stuck on 404 No Such Element with Espresso Driver #1

Closed dmertins closed 2 years ago

dmertins commented 2 years ago

I'm facing an issue when the element I look for is not present on screen. In that scenario, WD Proxy gets a 404 response and it gets stuck. The test client never receives the HTTP response, and the automation session never ends:

[HTTP] --> POST /session/3b607334-52e8-4dc9-9b06-79ded281d545/element
[HTTP] {"using":"xpath","value":"//*[@text='kkk']"}
[W3C (3b607334)] Driver proxy active, passing request on via HTTP proxy
[debug] [WD Proxy] Matched '/session/3b607334-52e8-4dc9-9b06-79ded281d545/element' to command name 'findElement'
[debug] [WD Proxy] Proxying [POST /session/3b607334-52e8-4dc9-9b06-79ded281d545/element] to [POST http://127.0.0.1:8300/session/a8785fde-283f-4bc4-b5fc-cf6cedbf1f4c/element] with body: {"using":"xpath","value":"//*[@text='kkk']"}
[WD Proxy] Got response with status 404: {"id":"3743e97d-a7d2-4f09-a776-f15eef7d8868","sessionId":"a8785fde-283f-4bc4-b5fc-cf6cedbf1f4c","value":{"error":"no such element","message":"Could not find espresso element with strategy XPATH and selector //*[@text='kkk']","stacktrace":"io.appium.espressoserver.lib.handlers.exceptions.NoSuchElementException: Could not find espresso element with strategy XPATH and selector //*[@text='kkk']\n\tat io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:39)\n\tat io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.invokeStrategy(RequestHandler.kt:35)\n\tat io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handleInternal(RequestHandler.kt:29)\n\tat io.appium.espressoserver.lib.handlers.FindE...

This is happening when automating the compose_playground.apk you provided, and with the same capabilities used in this repo. I'm using Appium Server v2.0.0-beta.25, espresso@2.0.1 and Appium-Python-Client 2.1.2.

dmertins commented 2 years ago

Setup:

Steps to reproduce the problem:

def android_compose_caps() { platformName: 'Android', deviceName: 'emulator-5556', app: File.join(File.dirname(FILE), '../' + 'compose_playground.apk'), automationName: 'espresso', newCommandTimeout: 0, skipUnlock: true, fullReset: false, forceEspressoRebuild: true, showGradleLog: true, espressoBuildConfig: '{"additionalAndroidTestDependencies": ["androidx.lifecycle:lifecycle-extensions:2.2.0", "androidx.activity:activity:1.3.1", "androidx.fragment:fragment:1.2.0"]}' } end

@driver = Appium::Driver.new({ caps: android_compose_caps, appium_lib: { server_url: "http://localhost:4723" } }, false) @driver.start_driver

Look for a non existent element:

non_existent_element = @driver.find_element(xpath: "//*[@text='Non Existent Text']")

Appium Server gets stuck on the above command and never returns the HTTP response to the test client.

- run the test script with `ruby test/jetpack_compose.rb`;
After running he script, Appium gets stuck on this request:

2022-02-21 11:28:40:011 - [HTTP] --> POST /session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/element 2022-02-21 11:28:40:012 - [HTTP] {"using":"xpath","value":"//[@text='Non Existent Text']"} 2022-02-21 11:28:40:015 - [W3C (33f3fb6e)] Driver proxy active, passing request on via HTTP proxy 2022-02-21 11:28:40:016 - [debug] [WD Proxy] Matched '/session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/element' to command name 'findElement' 2022-02-21 11:28:40:016 - [debug] [WD Proxy] Proxying [POST /session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/element] to [POST http://127.0.0.1:8300/session/8b4dfc7a-c32f-4282-89c2-8a268d85dd59/element] with body: {"using":"xpath","value":"//[@text='Non Existent Text']"} 2022-02-21 11:28:40:131 - [WD Proxy] Got response with status 404: {"id":"4e51fd71-c740-41e7-986b-87d71c84779a","sessionId":"8b4dfc7a-c32f-4282-89c2-8a268d85dd59","value":{"error":"no such element","message":"Could not find espresso element with strategy XPATH and selector //[@text='Non Existent Text']","stacktrace":"io.appium.espressoserver.lib.handlers.exceptions.NoSuchElementException: Could not find espresso element with strategy XPATH and selector //[@text='Non Existent Text']\n\tat io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:39)\n\tat io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.invokeStrategy(RequestHandler.kt:35)\n\tat io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handleInternal(RequestHandler.kt:29)\n\tat io.appium.espre...

Complete Appium Server Log:

2022-02-21 11:28:08:327 - [Appium] Welcome to Appium v2.0.0-beta.25 (REV 3fea5493a431ac64470d4230d4b51438cf213bd1) 2022-02-21 11:28:08:330 - [Appium] Non-default server args: 2022-02-21 11:28:08:331 - [Appium] { 2022-02-21 11:28:08:331 - [Appium] localTimezone: true, 2022-02-21 11:28:08:331 - [Appium] logTimestamp: true 2022-02-21 11:28:08:331 - [Appium] } 2022-02-21 11:28:08:332 - [Appium] Attempting to load driver espresso... 2022-02-21 11:28:09:253 - [Appium] Attempting to load driver uiautomator2... 2022-02-21 11:28:10:279 - [Appium] Appium REST http interface listener started on 0.0.0.0:4723 2022-02-21 11:28:10:280 - [Appium] Available drivers: 2022-02-21 11:28:10:280 - [Appium] - espresso@2.0.1 (automationName 'Espresso') 2022-02-21 11:28:10:280 - [Appium] - uiautomator2@2.0.3 (automationName 'UiAutomator2') 2022-02-21 11:28:10:281 - [Appium] No plugins have been installed. Use the "appium plugin" command to install the one(s) you want to use. 2022-02-21 11:28:29:911 - [debug] [HTTP] Request idempotency key: 0417621b-f088-4593-8e60-87c12c77cc81 2022-02-21 11:28:29:924 - [HTTP] --> POST /session 2022-02-21 11:28:29:924 - [HTTP] {"desiredCapabilities":{"platformName":"Android","deviceName":"emulator-5556","app":"/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk","automationName":"espresso","newCommandTimeout":0,"skipUnlock":true,"fullReset":false,"forceEspressoRebuild":true,"showGradleLog":true,"espressoBuildConfig":"{\"additionalAndroidTestDependencies\": [\"androidx.lifecycle:lifecycle-extensions:2.2.0\", \"androidx.activity:activity:1.3.1\", \"androidx.fragment:fragment:1.2.0\"]}"},"capabilities":{"firstMatch":[{"platformName":"Android","appium:deviceName":"emulator-5556","appium:app":"/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk","appium:automationName":"espresso","appium:newCommandTimeout":0,"appium:skipUnlock":true,"appium:fullReset":false,"appium:forceEspressoRebuild":true,"appium:showGradleLog":true,"appium:espressoBuildConfig":"{\"additionalAndroidTestDependencies\": [\"androidx.lifecycle:lifecycle-extensions:2.2.0\", \"androidx.activity:activity:1.3.1\", \"androidx.fra... 2022-02-21 11:28:29:925 - [debug] [W3C] Calling AppiumDriver.createSession() with args: [{"platformName":"Android","deviceName":"emulator-5556","app":"/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk","automationName":"espresso","newCommandTimeout":0,"skipUnlock":true,"fullReset":false,"forceEspressoRebuild":true,"showGradleLog":true,"espressoBuildConfig":"{\"additionalAndroidTestDependencies\": [\"androidx.lifecycle:lifecycle-extensions:2.2.0\", \"androidx.activity:activity:1.3.1\", \"androidx.fragment:fragment:1.2.0\"]}"},null,{"firstMatch":[{"platformName":"Android","appium:deviceName":"emulator-5556","appium:app":"/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk","appium:automationName":"espresso","appium:newCommandTimeout":0,"appium:skipUnlock":true,"appium:fullReset":false,"appium:forceEspressoRebuild":true,"appium:showGradleLog":true,"appium:espressoBuildConfig":"{\"additionalAndroidTestDependencies\": [\"androidx.lifecycle:lifecycle-extensions:2.2.0\", \"androidx.activity:activity:1.3.1\", \"androidx.fragment:fragment:1.2.0\"]}"}]}] 2022-02-21 11:28:29:926 - [debug] [BaseDriver] Event 'newSessionRequested' logged at 1645453709925 (11:28:29 GMT-0300 (Brasilia Standard Time)) 2022-02-21 11:28:29:929 - [Appium] Attempting to find matching driver for automationName 'espresso' and platformName 'Android' 2022-02-21 11:28:29:929 - [Appium] The 'espresso' driver was installed and matched caps. 2022-02-21 11:28:29:929 - [Appium] Will require it at /home/dmertins/.appium/appium-espresso-driver/node_modules/appium-espresso-driver 2022-02-21 11:28:29:930 - [Appium] Appium v2.0.0-beta.25 creating new EspressoDriver (v2.0.1) session 2022-02-21 11:28:29:930 - [Appium] Checking BaseDriver versions for Appium and EspressoDriver 2022-02-21 11:28:29:930 - [Appium] Appium's BaseDriver version is 8.2.4 2022-02-21 11:28:29:930 - [Appium] EspressoDriver's BaseDriver version is 8.2.4 2022-02-21 11:28:29:932 - [BaseDriver] Appium received (M)JSONWP desired capabilities in alongside the W3C capabilities; they will be ignored 2022-02-21 11:28:29:933 - [debug] [BaseDriver] Creating session with W3C capabilities: { 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "alwaysMatch": { 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "platformName": "Android", 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "appium:deviceName": "emulator-5556", 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "appium:app": "/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk", 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "appium:automationName": "espresso", 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "appium:newCommandTimeout": 0, 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "appium:skipUnlock": true, 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "appium:fullReset": false, 2022-02-21 11:28:29:933 - [debug] [BaseDriver] "appium:forceEspressoRebuild": true, 2022-02-21 11:28:29:934 - [debug] [BaseDriver] "appium:showGradleLog": true, 2022-02-21 11:28:29:934 - [debug] [BaseDriver] "appium:espressoBuildConfig": "{\"additionalAndroidTestDependencies\": [\"androidx.lifecycle:lifecycle-extensions:2.2.0\", \"androidx.activity:activity:1.3.1\", \"androidx.fragment:fragment:1.2.0\"]}" 2022-02-21 11:28:29:934 - [debug] [BaseDriver] }, 2022-02-21 11:28:29:934 - [debug] [BaseDriver] "firstMatch": [ 2022-02-21 11:28:29:934 - [debug] [BaseDriver] {} 2022-02-21 11:28:29:934 - [debug] [BaseDriver] ] 2022-02-21 11:28:29:934 - [debug] [BaseDriver] } 2022-02-21 11:28:29:942 - [BaseDriver] Session created with session id: 33f3fb6e-b0b6-4c91-9377-1c75429a5d2e 2022-02-21 11:28:29:945 - [BaseDriver] Using local app '/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk' 2022-02-21 11:28:29:964 - [debug] [Espresso] Checking whether app is actually present 2022-02-21 11:28:29:966 - [Espresso] EspressoDriver version: 2.0.1 2022-02-21 11:28:29:980 - [ADB] Found 4 'build-tools' folders under '/home/dmertins/Android/Sdk' (newest first): 2022-02-21 11:28:29:980 - [ADB] /home/dmertins/Android/Sdk/build-tools/32.0.0 2022-02-21 11:28:29:980 - [ADB] /home/dmertins/Android/Sdk/build-tools/30.0.3 2022-02-21 11:28:29:980 - [ADB] /home/dmertins/Android/Sdk/build-tools/30.0.2 2022-02-21 11:28:29:980 - [ADB] /home/dmertins/Android/Sdk/build-tools/29.0.2 2022-02-21 11:28:29:981 - [ADB] Using 'adb' from '/home/dmertins/Android/Sdk/platform-tools/adb' 2022-02-21 11:28:29:981 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 start-server' 2022-02-21 11:28:29:990 - [AndroidDriver] Retrieving device list 2022-02-21 11:28:29:990 - [debug] [ADB] Trying to find a connected android device 2022-02-21 11:28:29:990 - [debug] [ADB] Getting connected devices 2022-02-21 11:28:30:000 - [debug] [ADB] Connected devices: [{"udid":"emulator-5554","state":"device"}] 2022-02-21 11:28:30:000 - [AndroidDriver] Using device: emulator-5554 2022-02-21 11:28:30:001 - [ADB] Using 'adb' from '/home/dmertins/Android/Sdk/platform-tools/adb' 2022-02-21 11:28:30:001 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 start-server' 2022-02-21 11:28:30:010 - [debug] [ADB] Setting device id to emulator-5554 2022-02-21 11:28:30:011 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell getprop ro.build.version.sdk' 2022-02-21 11:28:30:042 - [debug] [ADB] Current device property 'ro.build.version.sdk': 30 2022-02-21 11:28:30:042 - [ADB] Getting device platform version 2022-02-21 11:28:30:042 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell getprop ro.build.version.release' 2022-02-21 11:28:30:066 - [debug] [ADB] Current device property 'ro.build.version.release': 11 2022-02-21 11:28:30:067 - [debug] [ADB] Device API level: 30 2022-02-21 11:28:30:067 - [Espresso] Relaxing hidden api policy 2022-02-21 11:28:30:067 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell 'settings put global hidden_api_policy_pre_p_apps 1;settings put global hidden_api_policy_p_apps 1;settings put global hidden_api_policy 1'' 2022-02-21 11:28:30:128 - [debug] [AndroidDriver] Parsing package and activity from app manifest 2022-02-21 11:28:30:144 - [ADB] Package name: 'com.example.jetpackcomposeplayground' 2022-02-21 11:28:30:144 - [ADB] Main activity name: 'com.example.jetpackcompose.core.MainActivity' 2022-02-21 11:28:30:144 - [debug] [AndroidDriver] Parsed package and activity are: com.example.jetpackcomposeplayground/com.example.jetpackcompose.core.MainActivity 2022-02-21 11:28:30:144 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 wait-for-device' 2022-02-21 11:28:30:153 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell echo ping' 2022-02-21 11:28:30:169 - [debug] [AndroidDriver] Pushing settings apk to device... 2022-02-21 11:28:30:170 - [debug] [ADB] Getting install status for io.appium.settings 2022-02-21 11:28:30:170 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys package io.appium.settings' 2022-02-21 11:28:30:195 - [debug] [ADB] 'io.appium.settings' is installed 2022-02-21 11:28:30:195 - [debug] [ADB] Getting package info for 'io.appium.settings' 2022-02-21 11:28:30:196 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys package io.appium.settings' 2022-02-21 11:28:30:233 - [debug] [ADB] The version name of the installed 'io.appium.settings' is greater or equal to the application version name ('4.0.0' >= '4.0.0') 2022-02-21 11:28:30:234 - [debug] [ADB] There is no need to install/upgrade '/home/dmertins/.appium/appium-espresso-driver/node_modules/appium-espresso-driver/node_modules/io.appium.settings/apks/settings_apk-debug.apk' 2022-02-21 11:28:30:234 - [debug] [ADB] Getting IDs of all 'io.appium.settings' processes 2022-02-21 11:28:30:234 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell 'pgrep --help; echo $?'' 2022-02-21 11:28:30:256 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell pgrep -f ([[:blank:]]|\^)io.appium.settings([[:blank:]]|\$)' 2022-02-21 11:28:30:323 - [debug] [AndroidDriver] io.appium.settings is already running. There is no need to reset its permissions. 2022-02-21 11:28:30:325 - [debug] [Logcat] Starting logs capture with command: /home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 logcat -v threadtime 2022-02-21 11:28:30:358 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell settings get global animator_duration_scale' 2022-02-21 11:28:30:389 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell settings get global transition_animation_scale' 2022-02-21 11:28:30:419 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell settings get global window_animation_scale' 2022-02-21 11:28:30:461 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell am broadcast -a io.appium.settings.animation -n io.appium.settings/.receivers.AnimationSettingReceiver --es setstatus disable' 2022-02-21 11:28:30:509 - [debug] [Espresso] Forwarding Espresso Server port 6791 to 8300 2022-02-21 11:28:30:510 - [debug] [ADB] Forwarding system: 8300 to device: 6791 2022-02-21 11:28:30:510 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 forward tcp:8300 tcp:6791' 2022-02-21 11:28:30:520 - [debug] [Espresso] 'skipUnlock' capability set, so skipping device unlock 2022-02-21 11:28:30:521 - [debug] [ADB] Checking app cert for /home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk 2022-02-21 11:28:30:546 - [ADB] Using 'apksigner.jar' from '/home/dmertins/Android/Sdk/build-tools/32.0.0/lib/apksigner.jar' 2022-02-21 11:28:30:547 - [debug] [ADB] Starting apksigner: /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Xmx1024M -Xss1m -jar /home/dmertins/Android/Sdk/build-tools/32.0.0/lib/apksigner.jar verify --print-certs /home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk 2022-02-21 11:28:31:022 - [debug] [ADB] apksigner stdout: Signer #1 certificate DN: EMAILADDRESS=android@android.com, CN=Android, OU=Android, O=Android, L=Mountain View, ST=California, C=US 2022-02-21 11:28:31:022 - [debug] [ADB] Signer #1 certificate SHA-256 digest: a40da80a59d170caa950cf15c18c454d47a39b26989d8b640ecd745ba71bf5dc 2022-02-21 11:28:31:022 - [debug] [ADB] Signer #1 certificate SHA-1 digest: 61ed377e85d386a8dfee6b864bd85b0bfaa5af81 2022-02-21 11:28:31:022 - [debug] [ADB] Signer #1 certificate MD5 digest: e89b158e4bcf988ebd09eb83f5378e87 2022-02-21 11:28:31:022 - [debug] [ADB] 2022-02-21 11:28:31:023 - [debug] [ADB] sha256 hash did match for 'compose_playground.apk' 2022-02-21 11:28:31:023 - [ADB] '/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk' is signed with the default certificate 2022-02-21 11:28:31:023 - [debug] [ADB] Getting install status for com.example.jetpackcomposeplayground 2022-02-21 11:28:31:023 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys package com.example.jetpackcomposeplayground' 2022-02-21 11:28:31:049 - [debug] [ADB] 'com.example.jetpackcomposeplayground' is installed 2022-02-21 11:28:31:049 - [debug] [ADB] Getting package info for 'com.example.jetpackcomposeplayground' 2022-02-21 11:28:31:049 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys package com.example.jetpackcomposeplayground' 2022-02-21 11:28:31:078 - [debug] [ADB] The version name of the installed 'com.example.jetpackcomposeplayground' is greater or equal to the application version name ('1.0.0' >= '1.0.0') 2022-02-21 11:28:31:079 - [debug] [ADB] There is no need to install/upgrade '/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk' 2022-02-21 11:28:31:079 - [AndroidDriver] Performing fast reset on 'com.example.jetpackcomposeplayground' 2022-02-21 11:28:31:079 - [debug] [ADB] Getting install status for com.example.jetpackcomposeplayground 2022-02-21 11:28:31:079 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys package com.example.jetpackcomposeplayground' 2022-02-21 11:28:31:109 - [debug] [ADB] 'com.example.jetpackcomposeplayground' is installed 2022-02-21 11:28:31:109 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell am force-stop com.example.jetpackcomposeplayground' 2022-02-21 11:28:31:141 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell pm clear com.example.jetpackcomposeplayground' 2022-02-21 11:28:31:179 - [debug] [AndroidDriver] Performed fast reset on the installed 'com.example.jetpackcomposeplayground' application (stop and clear) 2022-02-21 11:28:31:179 - [debug] [Espresso] 'forceEspressoRebuild' capability is enabled 2022-02-21 11:28:31:179 - [debug] [Espresso] Deleting the obsolete Espresso server package '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' 2022-02-21 11:28:31:183 - [Espresso] Loading the build configuration from 'espressoBuildConfig' capability 2022-02-21 11:28:31:183 - [Espresso] Building espresso server in '/tmp/espresso-server-emulator-5554' 2022-02-21 11:28:31:183 - [debug] [Espresso] The build folder root could be customized by changing the 'tmpDir' capability 2022-02-21 11:28:31:325 - [debug] [Espresso] Copying espresso server template from ('/home/dmertins/.appium/appium-espresso-driver/node_modules/appium-espresso-driver/espresso-server' to '/tmp/espresso-server-emulator-5554') 2022-02-21 11:28:31:555 - [debug] [Support] Traversed 52 directories and 281 files in 229ms 2022-02-21 11:28:31:555 - [debug] [Espresso] Bulding espresso server 2022-02-21 11:28:31:556 - [Espresso] Adding the following additionalAndroidTestDependencies to build.gradle.kts: androidTestImplementation("androidx.lifecycle:lifecycle-extensions:2.2.0"),androidTestImplementation("androidx.activity:activity:1.3.1"),androidTestImplementation("androidx.fragment:fragment:1.2.0") 2022-02-21 11:28:31:557 - [debug] [Espresso] Beginning build with command './gradlew -PappiumTargetPackage=com.example.jetpackcomposeplayground app:assembleAndroidTest' in directory '/tmp/espresso-server-emulator-5554' 2022-02-21 11:28:31:557 - [debug] [Espresso] Output from Gradle will be logged. To change this, use 'showGradleLog' desired capability 2022-02-21 11:28:32:426 - [Gradle] [STDOUT] > Task :app:preBuild UP-TO-DATE 2022-02-21 11:28:32:427 - [Gradle] [STDOUT] > Task :app:preDebugBuild UP-TO-DATE 2022-02-21 11:28:32:427 - [Gradle] [STDOUT] > Task :app:compileDebugAidl NO-SOURCE 2022-02-21 11:28:32:427 - [Gradle] [STDOUT] > Task :app:compileDebugRenderscript NO-SOURCE 2022-02-21 11:28:32:427 - [Gradle] [STDOUT] > Task :app:generateDebugBuildConfig FROM-CACHE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:checkDebugAarMetadata FROM-CACHE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:generateDebugResValues FROM-CACHE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:generateDebugResources UP-TO-DATE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:mergeDebugResources FROM-CACHE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:createDebugCompatibleScreenManifests FROM-CACHE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:extractDeepLinksDebug FROM-CACHE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:processDebugMainManifest FROM-CACHE 2022-02-21 11:28:32:428 - [Gradle] [STDOUT] > Task :app:processDebugManifest FROM-CACHE 2022-02-21 11:28:32:429 - [Gradle] [STDOUT] > Task :app:processDebugManifestForPackage FROM-CACHE 2022-02-21 11:28:32:523 - [Gradle] [STDOUT] > Task :app:processDebugResources FROM-CACHE 2022-02-21 11:28:32:922 - [Gradle] [STDOUT] > Task :app:compileDebugKotlin FROM-CACHE 2022-02-21 11:28:32:922 - [Gradle] [STDOUT] > Task :app:javaPreCompileDebug FROM-CACHE 2022-02-21 11:28:33:222 - [Gradle] [STDOUT] > Task :app:compileDebugJavaWithJavac FROM-CACHE 2022-02-21 11:28:33:223 - [Gradle] [STDOUT] > Task :app:bundleDebugClasses FROM-CACHE 2022-02-21 11:28:33:223 - [Gradle] [STDOUT] > Task :app:preDebugAndroidTestBuild SKIPPED 2022-02-21 11:28:33:223 - [Gradle] [STDOUT] > Task :app:compileDebugAndroidTestAidl NO-SOURCE 2022-02-21 11:28:33:323 - [Gradle] [STDOUT] > Task :app:processDebugAndroidTestManifest 2022-02-21 11:28:33:323 - [Gradle] [STDOUT] > Task :app:compileDebugAndroidTestRenderscript NO-SOURCE 2022-02-21 11:28:33:323 - [Gradle] [STDOUT] > Task :app:generateDebugAndroidTestBuildConfig FROM-CACHE 2022-02-21 11:28:33:323 - [Gradle] [STDOUT] > Task :app:checkDebugAndroidTestAarMetadata FROM-CACHE 2022-02-21 11:28:33:323 - [Gradle] [STDOUT] > Task :app:generateDebugAndroidTestResValues FROM-CACHE 2022-02-21 11:28:33:323 - [Gradle] [STDOUT] > Task :app:generateDebugAndroidTestResources UP-TO-DATE 2022-02-21 11:28:33:323 - [Gradle] [STDOUT] > Task :app:mergeDebugAndroidTestResources FROM-CACHE 2022-02-21 11:28:33:422 - [Gradle] [STDOUT] > Task :app:processDebugAndroidTestResources FROM-CACHE 2022-02-21 11:28:33:522 - [Gradle] [STDOUT] > Task :app:compileDebugAndroidTestKotlin FROM-CACHE 2022-02-21 11:28:33:522 - [Gradle] [STDOUT] > Task :app:javaPreCompileDebugAndroidTest FROM-CACHE 2022-02-21 11:28:33:622 - [Gradle] [STDOUT] > Task :app:compileDebugAndroidTestJavaWithJavac FROM-CACHE 2022-02-21 11:28:33:622 - [Gradle] [STDOUT] > Task :app:compileDebugAndroidTestSources UP-TO-DATE 2022-02-21 11:28:33:622 - [Gradle] [STDOUT] > Task :app:mergeDebugAndroidTestShaders FROM-CACHE 2022-02-21 11:28:33:623 - [Gradle] [STDOUT] > Task :app:compileDebugAndroidTestShaders NO-SOURCE 2022-02-21 11:28:33:623 - [Gradle] [STDOUT] > Task :app:generateDebugAndroidTestAssets UP-TO-DATE 2022-02-21 11:28:33:623 - [Gradle] [STDOUT] > Task :app:mergeDebugAndroidTestAssets FROM-CACHE 2022-02-21 11:28:33:623 - [Gradle] [STDOUT] > Task :app:compressDebugAndroidTestAssets FROM-CACHE 2022-02-21 11:28:33:623 - [Gradle] [STDOUT] > Task :app:processDebugAndroidTestJavaRes NO-SOURCE 2022-02-21 11:28:33:922 - [Gradle] [STDOUT] > Task :app:mergeDebugAndroidTestJavaResource FROM-CACHE 2022-02-21 11:28:33:922 - [Gradle] [STDOUT] > Task :app:mergeDebugAndroidTestJniLibFolders FROM-CACHE 2022-02-21 11:28:34:122 - [Gradle] [STDOUT] > Task :app:mergeDebugAndroidTestNativeLibs FROM-CACHE 2022-02-21 11:28:34:222 - [Gradle] [STDOUT] > Task :app:checkDebugAndroidTestDuplicateClasses FROM-CACHE 2022-02-21 11:28:34:222 - [Gradle] [STDOUT] > Task :app:desugarDebugAndroidTestFileDependencies 2022-02-21 11:28:34:422 - [Gradle] [STDOUT] > Task :app:mergeExtDexDebugAndroidTest FROM-CACHE 2022-02-21 11:28:34:422 - [Gradle] [STDOUT] > Task :app:mergeLibDexDebugAndroidTest FROM-CACHE 2022-02-21 11:28:34:422 - [Gradle] [STDOUT] > Task :app:dexBuilderDebugAndroidTest FROM-CACHE 2022-02-21 11:28:34:422 - [Gradle] [STDOUT] > Task :app:mergeProjectDexDebugAndroidTest FROM-CACHE 2022-02-21 11:28:34:423 - [Gradle] [STDOUT] > Task :app:validateSigningDebugAndroidTest FROM-CACHE 2022-02-21 11:28:34:822 - [Gradle] [STDOUT] > Task :app:packageDebugAndroidTest 2022-02-21 11:28:34:822 - [Gradle] [STDOUT] > Task :app:assembleDebugAndroidTest 2022-02-21 11:28:34:822 - [Gradle] [STDOUT] > Task :app:assembleAndroidTest 2022-02-21 11:28:34:848 - [Gradle] [STDOUT] 2022-02-21 11:28:34:849 - [Gradle] [STDOUT] BUILD SUCCESSFUL in 3s 2022-02-21 11:28:34:849 - [Gradle] [STDOUT] 37 actionable tasks: 3 executed, 34 from cache 2022-02-21 11:28:34:856 - [debug] [Espresso] Copying built apk from '/tmp/espresso-server-emulator-5554/app/build/outputs/apk/androidTest/debug/app-debug-androidTest.apk' to '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' 2022-02-21 11:28:34:867 - [debug] [ADB] Checking app cert for /tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk 2022-02-21 11:28:34:883 - [debug] [ADB] Starting apksigner: /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Xmx1024M -Xss1m -jar /home/dmertins/Android/Sdk/build-tools/32.0.0/lib/apksigner.jar verify --print-certs /tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk 2022-02-21 11:28:35:307 - [debug] [ADB] apksigner stdout: Signer #1 certificate DN: C=US, O=Android, CN=Android Debug 2022-02-21 11:28:35:307 - [debug] [ADB] Signer #1 certificate SHA-256 digest: ce17d3780c6fc179d5db00e383bde05a476e7a0c874a03fc02af30a9e3e5637b 2022-02-21 11:28:35:307 - [debug] [ADB] Signer #1 certificate SHA-1 digest: 7cfeda238206e75838cc6f81be7da0989eab0a07 2022-02-21 11:28:35:307 - [debug] [ADB] Signer #1 certificate MD5 digest: 9b9efdfed173c97dcd746baf5a8dc1b9 2022-02-21 11:28:35:307 - [debug] [ADB] 2022-02-21 11:28:35:308 - [ADB] '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' is signed with a non-default certificate 2022-02-21 11:28:35:309 - [ADB] Using 'zipalign' from '/home/dmertins/Android/Sdk/build-tools/32.0.0/zipalign' 2022-02-21 11:28:35:323 - [debug] [ADB] /tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' is already zip-aligned. Doing nothing 2022-02-21 11:28:35:323 - [debug] [ADB] Signing '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' with default cert 2022-02-21 11:28:35:323 - [debug] [ADB] Starting apksigner: /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Xmx1024M -Xss1m -jar /home/dmertins/Android/Sdk/build-tools/32.0.0/lib/apksigner.jar sign --key /home/dmertins/.appium/appium-espresso-driver/node_modules/appium-espresso-driver/node_modules/appium-android-driver/node_modules/appium-adb/keys/testkey.pk8 --cert /home/dmertins/.appium/appium-espresso-driver/node_modules/appium-espresso-driver/node_modules/appium-android-driver/node_modules/appium-adb/keys/testkey.x509.pem /tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk 2022-02-21 11:28:35:850 - [debug] [ADB] Uninstalling io.appium.espressoserver.test 2022-02-21 11:28:35:850 - [debug] [ADB] Getting install status for io.appium.espressoserver.test 2022-02-21 11:28:35:851 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys package io.appium.espressoserver.test' 2022-02-21 11:28:35:877 - [debug] [ADB] 'io.appium.espressoserver.test' is installed 2022-02-21 11:28:35:877 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell am force-stop io.appium.espressoserver.test' 2022-02-21 11:28:35:909 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 uninstall io.appium.espressoserver.test' 2022-02-21 11:28:36:179 - [debug] [ADB] 'adb uninstall io.appium.espressoserver.test' command output: Success 2022-02-21 11:28:36:179 - [ADB] io.appium.espressoserver.test was successfully uninstalled 2022-02-21 11:28:36:179 - [Espresso] Uninstalled the obsolete Espresso server package from the device under test 2022-02-21 11:28:36:180 - [debug] [ADB] Getting install status for io.appium.espressoserver.test 2022-02-21 11:28:36:180 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys package io.appium.espressoserver.test' 2022-02-21 11:28:36:263 - [debug] [ADB] 'io.appium.espressoserver.test' is not installed 2022-02-21 11:28:36:264 - [debug] [ADB] App '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' is not installed 2022-02-21 11:28:36:264 - [Espresso] Installing Espresso Test Server apk from the target device (path: '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk') 2022-02-21 11:28:36:265 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 help' 2022-02-21 11:28:36:279 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 features' 2022-02-21 11:28:36:294 - [ADB] The application at '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' will not be cached, because the device under test has confirmed the support of streamed installs 2022-02-21 11:28:36:295 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 install /tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' 2022-02-21 11:28:36:450 - [ADB] The installation of 'io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' took 155ms 2022-02-21 11:28:36:450 - [debug] [ADB] Install command stdout: Serving... 2022-02-21 11:28:36:450 - [debug] [ADB] Performing Incremental Install 2022-02-21 11:28:36:450 - [debug] [ADB] Success 2022-02-21 11:28:36:450 - [debug] [ADB] Install command complete in 132 ms 2022-02-21 11:28:36:451 - [Espresso] Installed Espresso Test Server apk '/tmp/io.appium.espressoserver.test_2.0.1_com.example.jetpackcomposeplayground_emulator-5554.apk' (pkg: 'io.appium.espressoserver.test') 2022-02-21 11:28:36:452 - [ADB] Adding packages ["io.appium.settings","io.appium.espressoserver.test"] to Doze whitelist 2022-02-21 11:28:36:453 - [debug] [ADB] Got the following command chunks to execute: [["dumpsys","deviceidle","whitelist","+io.appium.settings",";","dumpsys","deviceidle","whitelist","+io.appium.espressoserver.test",";"]] 2022-02-21 11:28:36:453 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys deviceidle whitelist +io.appium.settings ; dumpsys deviceidle whitelist +io.appium.espressoserver.test ;' 2022-02-21 11:28:36:553 - [debug] [Espresso] Performing cleanup of automation leftovers 2022-02-21 11:28:36:565 - [debug] [Espresso] No obsolete sessions have been detected (socket hang up) 2022-02-21 11:28:36:565 - [Espresso] Starting Espresso Server v2.0.1 with cmd: adb shell am instrument -w -e debug false -e disableAnalytics true io.appium.espressoserver.test/androidx.test.runner.AndroidJUnitRunner 2022-02-21 11:28:36:565 - [debug] [ADB] Creating ADB subprocess with args: ["-P",5037,"-s","emulator-5554","shell","am","instrument","-w","-e","debug",false,"-e","disableAnalytics",true,"io.appium.espressoserver.test/androidx.test.runner.AndroidJUnitRunner"] 2022-02-21 11:28:36:578 - [Espresso] Waiting up to 45000ms for Espresso server to be online 2022-02-21 11:28:36:580 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2022-02-21 11:28:36:581 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8300/status] with no body 2022-02-21 11:28:36:587 - [WD Proxy] socket hang up 2022-02-21 11:28:37:088 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2022-02-21 11:28:37:089 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8300/status] with no body 2022-02-21 11:28:37:092 - [WD Proxy] socket hang up 2022-02-21 11:28:37:592 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2022-02-21 11:28:37:592 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8300/status] with no body 2022-02-21 11:28:37:595 - [WD Proxy] socket hang up 2022-02-21 11:28:38:095 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2022-02-21 11:28:38:096 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8300/status] with no body 2022-02-21 11:28:38:099 - [WD Proxy] socket hang up 2022-02-21 11:28:38:600 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2022-02-21 11:28:38:600 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8300/status] with no body 2022-02-21 11:28:38:603 - [WD Proxy] socket hang up 2022-02-21 11:28:38:605 - [debug] [Espresso] [Instrumentation] io.appium.espressoserver.EspressoServerRunnerTest: 2022-02-21 11:28:39:104 - [debug] [WD Proxy] Matched '/status' to command name 'getStatus' 2022-02-21 11:28:39:104 - [debug] [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8300/status] with no body 2022-02-21 11:28:39:144 - [debug] [WD Proxy] Got response with status 200: {"id":"bd4fa195-539a-456b-b081-d701e5553f73","sessionId":null,"value":null} 2022-02-21 11:28:39:144 - [Espresso] Espresso server is online. The initialization process took 2578ms 2022-02-21 11:28:39:144 - [Espresso] Starting the session 2022-02-21 11:28:39:144 - [debug] [WD Proxy] Matched '/session' to command name 'createSession' 2022-02-21 11:28:39:144 - [debug] [WD Proxy] Proxying [POST /session] to [POST http://127.0.0.1:8300/session] with body: {"capabilities":{"firstMatch":[{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","deviceName":"emulator-5556","app":"/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk","automationName":"espresso","newCommandTimeout":0,"skipUnlock":true,"fullReset":false,"forceEspressoRebuild":true,"showGradleLog":true,"espressoBuildConfig":"{\"additionalAndroidTestDependencies\": [\"androidx.lifecycle:lifecycle-extensions:2.2.0\", \"androidx.activity:activity:1.3.1\", \"androidx.fragment:fragment:1.2.0\"]}"},"platformName":"Android","deviceName":"emulator-5554","app":"/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk","automationName":"espresso","newCommandTimeout":0,"skipUnlock":true,"fullReset":false,"forceEspressoRebuild":true,"showGradleLog":true,"espressoBuildConfig":"{\"additionalAndroidTestDe... 2022-02-21 11:28:39:767 - [debug] [WD Proxy] Got response with status 200: {"id":"6443bb04-2ea1-4a4d-97b1-26212f1b2d0c","sessionId":"8b4dfc7a-c32f-4282-89c2-8a268d85dd59","value":{}} 2022-02-21 11:28:39:767 - [WD Proxy] Determined the downstream protocol as 'W3C' 2022-02-21 11:28:39:767 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell 'echo "com.example.jetpackcomposeplayground" > "/data/local/tmp/espresso.apppackage"'' 2022-02-21 11:28:39:793 - [Espresso] Recorded the target application package 'com.example.jetpackcomposeplayground' to /data/local/tmp/espresso.apppackage 2022-02-21 11:28:39:794 - [debug] [ADB] Waiting up to 20000ms for activity matching pkg: 'com.example.jetpackcomposeplayground' and activity: 'com.example.jetpackcompose.core.MainActivity' to be focused 2022-02-21 11:28:39:794 - [debug] [ADB] Possible activities, to be checked: 'com.example.jetpackcompose.core.MainActivity', 'com.example.jetpackcomposeplayground.com.example.jetpackcompose.core.MainActivity' 2022-02-21 11:28:39:794 - [debug] [ADB] Getting focused package and activity 2022-02-21 11:28:39:795 - [debug] [ADB] Running '/home/dmertins/Android/Sdk/platform-tools/adb -P 5037 -s emulator-5554 shell dumpsys window displays' 2022-02-21 11:28:39:863 - [debug] [ADB] Found package: 'com.example.jetpackcomposeplayground' and fully qualified activity name : 'com.example.jetpackcompose.core.MainActivity' 2022-02-21 11:28:39:875 - [debug] [WD Proxy] Proxying [GET /appium/device/info] to [GET http://127.0.0.1:8300/session/8b4dfc7a-c32f-4282-89c2-8a268d85dd59/appium/device/info] with no body 2022-02-21 11:28:39:917 - [debug] [WD Proxy] Got response with status 200: {"id":"860691de-a991-45ee-907d-2434af600971","sessionId":"8b4dfc7a-c32f-4282-89c2-8a268d85dd59","value":{"realDisplaySize":"1080x2280","apiVersion":"30","carrierName":"Android","platformVersion":"11","timeZone":"America/Sao_Paulo","model":"sdk_gphone_x86","locale":"en_US","brand":"google","androidId":"9ff712771bcdbfd4","manufacturer":"Google","displayDensity":440}} 2022-02-21 11:28:39:920 - [Appium] New EspressoDriver session created successfully, session 33f3fb6e-b0b6-4c91-9377-1c75429a5d2e added to master session list 2022-02-21 11:28:39:925 - [debug] [BaseDriver] Event 'newSessionStarted' logged at 1645453719925 (11:28:39 GMT-0300 (Brasilia Standard Time)) 2022-02-21 11:28:39:928 - [debug] [W3C (33f3fb6e)] Cached the protocol value 'W3C' for the new session 33f3fb6e-b0b6-4c91-9377-1c75429a5d2e 2022-02-21 11:28:39:931 - [debug] [W3C (33f3fb6e)] Responding to client with driver.createSession() result: {"capabilities":{"platformName":"Android","deviceName":"emulator-5556","app":"/home/dmertins/Programming/Appium-Jetpack-Compose/compose_playground.apk","automationName":"espresso","newCommandTimeout":0,"skipUnlock":true,"fullReset":false,"forceEspressoRebuild":true,"showGradleLog":true,"espressoBuildConfig":"{\"additionalAndroidTestDependencies\": [\"androidx.lifecycle:lifecycle-extensions:2.2.0\", \"androidx.activity:activity:1.3.1\", \"androidx.fragment:fragment:1.2.0\"]}"}} 2022-02-21 11:28:39:947 - [HTTP] <-- POST /session 200 10016 ms - 543 2022-02-21 11:28:39:948 - [HTTP] 2022-02-21 11:28:39:978 - [HTTP] --> POST /session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/timeouts 2022-02-21 11:28:39:979 - [HTTP] {"implicit":0} 2022-02-21 11:28:39:990 - [debug] [W3C (33f3fb6e)] Calling AppiumDriver.timeouts() with args: [null,null,null,null,0,"33f3fb6e-b0b6-4c91-9377-1c75429a5d2e"] 2022-02-21 11:28:39:996 - [debug] [BaseDriver] W3C timeout argument: {"implicit":0}} 2022-02-21 11:28:39:997 - [debug] [BaseDriver] Set implicit wait to 0ms 2022-02-21 11:28:39:999 - [debug] [W3C (33f3fb6e)] Responding to client with driver.timeouts() result: null 2022-02-21 11:28:40:001 - [HTTP] <-- POST /session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/timeouts 200 22 ms - 14 2022-02-21 11:28:40:001 - [HTTP] 2022-02-21 11:28:40:005 - [HTTP] --> GET /status 2022-02-21 11:28:40:006 - [HTTP] {} 2022-02-21 11:28:40:006 - [debug] [GENERIC] Calling AppiumDriver.getStatus() with args: [] 2022-02-21 11:28:40:008 - [debug] [GENERIC] Responding to client with driver.getStatus() result: {"build":{"version":"2.0.0-beta.25","git-sha":"3fea5493a431ac64470d4230d4b51438cf213bd1","built":"2021-03-29 12:49:10 -0700"}} 2022-02-21 11:28:40:010 - [HTTP] <-- GET /status 200 3 ms - 153 2022-02-21 11:28:40:010 - [HTTP] 2022-02-21 11:28:40:011 - [HTTP] --> POST /session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/element 2022-02-21 11:28:40:012 - [HTTP] {"using":"xpath","value":"//[@text='Non Existent Text']"} 2022-02-21 11:28:40:015 - [W3C (33f3fb6e)] Driver proxy active, passing request on via HTTP proxy 2022-02-21 11:28:40:016 - [debug] [WD Proxy] Matched '/session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/element' to command name 'findElement' 2022-02-21 11:28:40:016 - [debug] [WD Proxy] Proxying [POST /session/33f3fb6e-b0b6-4c91-9377-1c75429a5d2e/element] to [POST http://127.0.0.1:8300/session/8b4dfc7a-c32f-4282-89c2-8a268d85dd59/element] with body: {"using":"xpath","value":"//[@text='Non Existent Text']"} 2022-02-21 11:28:40:131 - [WD Proxy] Got response with status 404: {"id":"4e51fd71-c740-41e7-986b-87d71c84779a","sessionId":"8b4dfc7a-c32f-4282-89c2-8a268d85dd59","value":{"error":"no such element","message":"Could not find espresso element with strategy XPATH and selector //[@text='Non Existent Text']","stacktrace":"io.appium.espressoserver.lib.handlers.exceptions.NoSuchElementException: Could not find espresso element with strategy XPATH and selector //[@text='Non Existent Text']\n\tat io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:39)\n\tat io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.invokeStrategy(RequestHandler.kt:35)\n\tat io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27)\n\tat io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handleInternal(RequestHandler.kt:29)\n\tat io.appium.espre...

Android Logcat:

2022-02-21 11:28:23.844 380-380/? W/adbd: timeout expired while flushing socket, closing 2022-02-21 11:28:29.413 6590-6592/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:29.442 6600-6602/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:29.703 6623-6625/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:29.733 6628-6630/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:29.773 6633-6635/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:29.818 5300-5300/io.appium.settings D/AbstractSettingHandler: Disabling animation 2022-02-21 11:28:29.821 6638-6640/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:30.454 525-540/? I/ActivityManager: Force stopping com.example.jetpackcomposeplayground appid=10215 user=0: from pid 6655 2022-02-21 11:28:30.455 6655-6657/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:30.458 857-857/? D/CarrierSvcBindHelper: No carrier app for: 0 2022-02-21 11:28:30.483 525-4401/? I/ActivityManager: Force stopping com.example.jetpackcomposeplayground appid=10215 user=0: clear data 2022-02-21 11:28:30.484 525-562/? I/ActivityManager: Force stopping com.example.jetpackcomposeplayground appid=10215 user=-1: clearApplicationUserData 2022-02-21 11:28:30.488 414-414/? I/keystore: clear_uid 10215 2022-02-21 11:28:30.490 6660-6662/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:30.495 857-857/? D/CarrierSvcBindHelper: No carrier app for: 0 2022-02-21 11:28:30.498 2410-2410/? I/CarrierServices: [2] RcsAutoStartReceiver.a: enableRcs changed from true to true 2022-02-21 11:28:30.518 1311-4256/? I/MediaProvider: Begin Intent { act=android.intent.action.PACKAGE_DATA_CLEARED dat=package:com.example.jetpackcomposeplayground flg=0x1000010 cmp=com.google.android.providers.media.module/com.android.providers.media.MediaService (has extras) } 2022-02-21 11:28:30.522 1090-6666/? I/Fitness: FitCleanupIntentOperation received Intent android.intent.action.PACKAGE_DATA_CLEARED [CONTEXT service_id=17 ] 2022-02-21 11:28:30.526 15481-4718/? I/Icing: doRemovePackageData com.example.jetpackcomposeplayground 2022-02-21 11:28:30.533 1311-4256/? I/MediaProvider: End Intent { act=android.intent.action.PACKAGE_DATA_CLEARED dat=package:com.example.jetpackcomposeplayground flg=0x1000010 cmp=com.google.android.providers.media.module/com.android.providers.media.MediaService (has extras) } 2022-02-21 11:28:30.534 5642-5674/? I/ProvidersCache: Provider returned no roots. Possibly naughty: com.google.android.apps.docs.storage 2022-02-21 11:28:34.844 504-504/? E/netmgr: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:network' service: Invalid argument 2022-02-21 11:28:34.844 504-504/? E/netmgr: Failed to open QEMU pipe 'qemud:network': Invalid argument 2022-02-21 11:28:35.178 506-506/? E/wifi_forwarder: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:wififorward' service: Invalid argument 2022-02-21 11:28:35.178 506-506/? E/wifi_forwarder: RemoteConnection failed to initialize: RemoteConnection failed to open pipe 2022-02-21 11:28:35.223 525-540/? I/ActivityManager: Force stopping io.appium.espressoserver.test appid=10217 user=0: from pid 6683 2022-02-21 11:28:35.224 6683-6685/? I/cmd: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:35.225 857-857/? D/CarrierSvcBindHelper: No carrier app for: 0 2022-02-21 11:28:35.252 525-562/? I/ActivityManager: Force stopping io.appium.espressoserver.test appid=10217 user=-1: deletePackageX 2022-02-21 11:28:35.317 414-414/? I/keystore: clear_uid 10217 2022-02-21 11:28:35.318 525-579/? E/PermissionMonitor: unknown permission type: -1for uid: 10217 2022-02-21 11:28:35.480 525-579/? I/system_server: Explicit concurrent copying GC freed 312222(15MB) AllocSpace objects, 106(4932KB) LOS objects, 49% free, 16MB/33MB, paused 56us total 161.487ms 2022-02-21 11:28:35.481 525-535/? W/JavaBinder: BinderProxy is being destroyed but the application did not call unlinkToDeath to unlink all of its death recipients beforehand. Releasing leaked death recipient: com.android.server.AlarmManagerService$2 2022-02-21 11:28:35.481 525-535/? I/BpBinder: onLastStrongRef automatically unlinking death recipients: 2022-02-21 11:28:35.481 525-535/? W/JavaBinder: BinderProxy is being destroyed but the application did not call unlinkToDeath to unlink all of its death recipients beforehand. Releasing leaked death recipient: com.android.server.AlarmManagerService$2 2022-02-21 11:28:35.481 525-535/? I/BpBinder: onLastStrongRef automatically unlinking death recipients: 2022-02-21 11:28:35.482 525-579/? I/incfs-dataloaderconnector: Reported status back to IncrementalService. DataLoaderId=87, status=0 2022-02-21 11:28:35.483 525-579/? I/IncrementalService: Unmounting and cleaning up mount 87 with root '/data/incremental/MT_data_app_vmdl151' 2022-02-21 11:28:35.483 525-579/? I/IncrementalService: bind: /data/app/~~2jct7y50nYojH9l9ztmjRA== 2022-02-21 11:28:35.484 525-579/? I/IncrementalService: root: /data/incremental/MT_data_app_vmdl151 2022-02-21 11:28:35.485 525-535/? W/JavaBinder: BinderProxy is being destroyed but the application did not call unlinkToDeath to unlink all of its death recipients beforehand. Releasing leaked death recipient: com.android.server.AlarmManagerService$2 2022-02-21 11:28:35.485 525-535/? I/BpBinder: onLastStrongRef automatically unlinking death recipients: 2022-02-21 11:28:35.493 525-579/? I/ActivityManager: Force stopping io.appium.espressoserver.test appid=10217 user=0: pkg removed 2022-02-21 11:28:35.498 525-621/? V/StorageManagerService: Package io.appium.espressoserver.test does not have legacy storage 2022-02-21 11:28:35.498 1311-1311/? I/MediaProvider: Invalidating LocalCallingIdentity cache for package io.appium.espressoserver.test. Reason: package android.intent.action.PACKAGE_REMOVED 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.android.musicfx/.Compatibility$Receiver 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.android.vending/com.google.android.finsky.packagemanager.impl.PackageMonitorReceiverImpl$RegisteredReceiver 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.android.vending/com.google.android.finsky.instantapps.appmanagement.InstantAppRemoveMonitor 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.apps.maps/com.google.android.libraries.social.peoplekit.thirdparty.viewcontrollers.ThirdPartyReceiver 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.apps.photos/com.google.android.libraries.social.peoplekit.thirdparty.viewcontrollers.ThirdPartyReceiver 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.gms/.games.chimera.GamesSystemBroadcastReceiverProxy 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver 2022-02-21 11:28:35.503 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.googlequicksearchbox/com.google.android.apps.gsa.googlequicksearchbox.GelStubAppWatcher 2022-02-21 11:28:35.503 1667-1667/? I/GsaVoiceInteractionSrv: O received Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } 2022-02-21 11:28:35.503 6261-6261/? I/Finsky: [2] nyl.i(0): PackageMonitorReceiverImpl - Received: android.intent.action.PACKAGE_REMOVED, [8isIk55MHOSvSL4G9NjEPBtem7gYUdqMEtfvpVWwS8Y] 2022-02-21 11:28:35.504 6261-6261/? I/Finsky: [2] nzb.n(8): Invalidating cached PackageState for io.appium.espressoserver.test 2022-02-21 11:28:35.507 525-601/? I/RollbackManager: broadcast=ACTION_PACKAGE_FULLY_REMOVED pkg=io.appium.espressoserver.test 2022-02-21 11:28:35.507 6261-6261/? I/Finsky: [2] nzb.s(3): Package no longer installed: io.appium.espressoserver.test 2022-02-21 11:28:35.511 525-609/? I/InputReader: Reconfiguring input devices, changes=KEYBOARD_LAYOUTS | 2022-02-21 11:28:35.512 525-551/? I/RoleManagerService: Granting default roles... 2022-02-21 11:28:35.512 525-551/? E/PackageManager: failed to find package io.appium.espressoserver.test 2022-02-21 11:28:35.512 525-551/? E/OverlayManager: Failed to change enabled overlays for io.appium.espressoserver.test user 0 2022-02-21 11:28:35.520 6261-6261/? I/Finsky: [2] xed.c(3): Do not start WearSupportService due to Wear service optimization 2022-02-21 11:28:35.522 6261-6693/? I/Finsky: [2295] ijf.run(2): Frosting DB delete succeeded: true 2022-02-21 11:28:35.525 6261-6296/? I/Finsky: [2238] kar.g(1): Installer: package io.appium.espressoserver.test was removed. replacing: false 2022-02-21 11:28:35.536 6261-6296/? I/Finsky: [2238] kar.T(17): Installer: Notifying status update. package=io.appium.espressoserver.test, status=UNINSTALLED, isid=NA 2022-02-21 11:28:35.538 2410-2410/? E/CarrierServices: [2] ecr.a: Invalid signature found for com.android.contacts: 18B66F4996F3D01CEAD29D3A3AA81801E7950B82 2022-02-21 11:28:35.541 857-857/? D/CarrierSvcBindHelper: No carrier app for: 0 2022-02-21 11:28:35.544 2410-2410/? E/CarrierServices: [2] ecr.a: Invalid signature found for com.android.contacts: 18B66F4996F3D01CEAD29D3A3AA81801E7950B82 2022-02-21 11:28:35.547 525-525/? W/WifiService: Couldn't get PackageInfo for package:io.appium.espressoserver.test 2022-02-21 11:28:35.547 525-525/? D/WifiService: Remove settings for package:io.appium.espressoserver.test 2022-02-21 11:28:35.555 5642-5674/? I/ProvidersCache: Provider returned no roots. Possibly naughty: com.google.android.apps.docs.storage 2022-02-21 11:28:35.560 6261-6261/? I/Finsky: [2] rja.a(8): Clearing split related stale data. 2022-02-21 11:28:35.560 6261-6706/? I/Finsky: [2304] fde.accept(35): Asset module storage cleared for package io.appium.espressoserver.test. 2022-02-21 11:28:35.564 6261-6261/? I/Finsky: [2] nzb.s(3): Package no longer installed: io.appium.espressoserver.test 2022-02-21 11:28:35.565 6261-6261/? I/Finsky: [2] kar.S(7): Installer: found apps to install. isMultiUserMode=false, apps=[] 2022-02-21 11:28:35.565 6261-6693/? I/Finsky: [2295] ijf.run(2): Frosting DB delete succeeded: false 2022-02-21 11:28:35.565 6261-6701/? I/Finsky: [2300] kii.E(2): IQ: Notifying installation update. [Package:io.appium.espressoserver.test, isid:dummysessionid], status=UNINSTALLED 2022-02-21 11:28:35.574 525-525/? W/WifiService: Couldn't get PackageInfo for package:io.appium.espressoserver.test 2022-02-21 11:28:35.574 525-525/? D/WifiService: Remove settings for package:io.appium.espressoserver.test 2022-02-21 11:28:35.576 525-525/? I/ConditionProviders: Disallowing condition provider io.appium.espressoserver.test 2022-02-21 11:28:35.579 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.584 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.584 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.585 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.586 1090-6714/? I/Fitness: FitCleanupIntentOperation received Intent android.intent.action.PACKAGE_REMOVED [CONTEXT service_id=17 ] 2022-02-21 11:28:35.586 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.587 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.587 15481-6668/? I/BlockstoreStorage: Clearing all the Blockstore Data for package io.appium.espressoserver.test [CONTEXT service_id=258 ] 2022-02-21 11:28:35.588 15481-6668/? I/BlockstoreStorage: Clearing all the Blockstore Data for 1 packages [CONTEXT service_id=258 ] 2022-02-21 11:28:35.588 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.592 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.592 6261-6710/? I/Finsky: [2305] ue.invoke(43): [ContentSync] finished, scheduled=false 2022-02-21 11:28:35.594 6261-6261/? I/Finsky: [2] nyl.i(0): PackageMonitorReceiverImpl - Received: android.intent.action.PACKAGE_FULLY_REMOVED, [8isIk55MHOSvSL4G9NjEPBtem7gYUdqMEtfvpVWwS8Y] 2022-02-21 11:28:35.594 6261-6261/? I/Finsky: [2] nzb.n(8): Invalidating cached PackageState for io.appium.espressoserver.test 2022-02-21 11:28:35.597 6261-6261/? I/Finsky: [2] nzb.s(3): Package no longer installed: io.appium.espressoserver.test 2022-02-21 11:28:35.597 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.598 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.598 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.599 6261-6693/? I/Finsky: [2295] ijf.run(2): Frosting DB delete succeeded: false 2022-02-21 11:28:35.600 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.601 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.602 6261-6261/? I/Finsky: [2] nyl.i(0): PackageMonitorReceiverImpl - Deduping intent android.intent.action.PACKAGE_FULLY_REMOVED 2022-02-21 11:28:35.607 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.608 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.608 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.609 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.610 328-4316/? I/chatty: uid=1041(audioserver) Binder:328_4 identical 1 line 2022-02-21 11:28:35.617 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.617 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.619 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.619 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.621 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.621 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.623 328-4316/? I/chatty: uid=1041(audioserver) Binder:328_4 identical 2 lines 2022-02-21 11:28:35.624 328-4316/? D/AF::TrackHandle: OpPlayAudio: track:56 usage:13 not muted 2022-02-21 11:28:35.626 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.626 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.627 5173-5173/? I/abb: StartCommandInProcess(73657474696e67730067657400656e61 settings.get.ena [truncated]) 2022-02-21 11:28:35.628 5173-27212/? I/abb: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:35.630 15481-4718/? I/Icing: doRemovePackageData io.appium.espressoserver.test 2022-02-21 11:28:35.630 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.631 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.631 5173-5173/? I/abb: StartCommandInProcess(7061636b61676500696e7374616c6c2d package.install- [truncated]) 2022-02-21 11:28:35.633 328-5452/? D/AF::TrackHandle: OpPlayAudio: track:57 usage:13 not muted 2022-02-21 11:28:35.639 15481-6670/? W/SQLiteLog: (28) double-quoted string literal: "io.appium.espressoserver.test" 2022-02-21 11:28:35.639 1000-1000/? D/Launcher.Model: package removed received io.appium.espressoserver.test 2022-02-21 11:28:35.640 15481-5573/? I/ContentMaintenance: Internal cache bytes used: 0; limit: 100000000; download size: 0 2022-02-21 11:28:35.641 15481-15599/? I/Icing: IndexChimeraService.getServiceInterface callingPackage=com.google.android.gms componentName=AppsCorpus serviceId=36 2022-02-21 11:28:35.643 6261-6261/? I/Finsky: [2] pnp.lB(4): PIM: Handling install package event for: io.appium.espressoserver.test status: UNINSTALLED 2022-02-21 11:28:35.645 1000-1046/? D/PackageUpdatedTask: Removing app iconio.appium.espressoserver.test 2022-02-21 11:28:35.646 1000-1046/? D/ModelWriter: removing items from db java.lang.Exception at com.android.launcher3.model.ModelWriter.deleteItemsFromDatabase(SourceFile:4) at com.android.launcher3.model.BaseModelUpdateTask.deleteAndBindComponentsRemoved(SourceFile:2) at com.android.launcher3.model.PackageUpdatedTask.execute(SourceFile:158) at com.android.launcher3.model.BaseModelUpdateTask.run(SourceFile:2) at android.os.Handler.handleCallback(Handler.java:938) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loop(Looper.java:223) at android.os.HandlerThread.run(HandlerThread.java:67) 2022-02-21 11:28:35.647 6261-6701/? I/Finsky: [2300] kii.D(6): IQ: Pruning inactive install requests 2022-02-21 11:28:35.648 6261-6701/? I/Finsky: [2300] kii.D(45): IQ: No matching installs to run for jobs: [] 2022-02-21 11:28:35.652 525-587/? I/IncrementalService: createStorage: /data/app/vmdl1340592677.tmp | 5 2022-02-21 11:28:35.622 525-525/? W/Binder:525_1E: type=1400 audit(0.0:3585): avc: denied { getopt } for scontext=u:r:system_server:s0 tcontext=u:r:shell:s0 tclass=unix_stream_socket permissive=0 2022-02-21 11:28:35.654 525-587/? I/incfs-mounts: [incfs] Loaded incremental-fs mount info: 1 instances, 1 mount points 2022-02-21 11:28:35.655 525-587/? W/incfs: [incfs] couldn't change file mode to 0777: Invalid argument 2022-02-21 11:28:35.656 180-180/? I/incfs-mounts: [incfs] Loaded incremental-fs mount info: 1 instances, 1 mount points 2022-02-21 11:28:35.622 525-525/? W/Binder:525_1E: type=1400 audit(0.0:3587): avc: denied { getopt } for scontext=u:r:system_server:s0 tcontext=u:r:shell:s0 tclass=unix_stream_socket permissive=0 2022-02-21 11:28:35.664 525-587/? I/incfs-mounts: [incfs] Loaded incremental-fs mount info: 1 instances, 2 mount points 2022-02-21 11:28:35.666 525-587/? I/IncrementalService: created storage 89 2022-02-21 11:28:35.666 525-525/? I/incfs-dataloaderconnector: DataLoader::create1 cmd: 336|/data/incremental/MT_data_app_vmdl134/mount/.pending_reads (deleted) 2022-02-21 11:28:35.666 525-525/? I/incfs-dataloaderconnector: DataLoader::create1 pendingReads: 340|/data/incremental/MT_data_app_vmdl134/mount/.pending_reads (deleted) 2022-02-21 11:28:35.667 525-525/? I/incfs-dataloaderconnector: DataLoader::create1 log: 344|/data/incremental/MT_data_app_vmdl134/mount/.log (deleted) 2022-02-21 11:28:35.667 525-525/? I/incfs-dataloaderconnector: DataLoader::create2: 2|android|com.android.server.pm.PackageManagerShellCommandDataLoader|shellCommandId=1136686374 2022-02-21 11:28:35.667 525-525/? I/incfs-dataloaderconnector: Reported status back to IncrementalService. DataLoaderId=89, status=2 2022-02-21 11:28:35.667 525-587/? E/PackageManagerShellCommandDataLoader-jni: onPrepareImage: start. 2022-02-21 11:28:35.668 525-587/? E/PackageManagerShellCommandDataLoader-jni: onPrepareImage: done, proceeding to streaming. 2022-02-21 11:28:35.668 525-587/? I/PackageManagerShellCommandDataLoader-jni: Started streaming... 2022-02-21 11:28:35.668 525-587/? I/incfs-dataloaderconnector: Reported status back to IncrementalService. DataLoaderId=89, status=5 2022-02-21 11:28:35.668 525-587/? I/incfs-dataloaderconnector: Reported status back to IncrementalService. DataLoaderId=89, status=3 2022-02-21 11:28:35.673 6261-6261/? I/Finsky: [2] kej.a(28): IQ::HLD: previousAllInstallsDone is Optional.empty, allInstallationsDone is Optional[true] 2022-02-21 11:28:35.674 6261-6261/? I/Finsky: [2] kej.a(30): IQ::HLD: Updating installations status false cross profiles 2022-02-21 11:28:35.674 6261-6261/? I/Finsky: [2] ghn.b(1): XPF:Binding for 10004181 2022-02-21 11:28:35.680 6261-6261/? I/Finsky: [2] ProfileStateService.onCreate(1): XPF:creating profileStateService 2022-02-21 11:28:35.681 6261-6261/? I/Finsky: [2] ghj.a(3): XPF:Registering listener 58165368 for user UserHandle{0}. 2022-02-21 11:28:35.685 6261-6261/? I/Finsky: [2] ghj.b(4): XPF:User UserHandle{0} finished enterprise setup, removing profile. 2022-02-21 11:28:35.686 6261-6261/? I/Finsky: [2] ghj.c(3): XPF:User UserHandle{0} is not in installation anymore, removing profile. 2022-02-21 11:28:35.686 6261-6261/? I/Finsky: [2] ghj.c(5): XPF:Notifying user UserHandle{0} that all installs are finished 2022-02-21 11:28:35.686 6261-6261/? I/Finsky: [2] ghn.d(1): XPF:unbinding for 10004181 2022-02-21 11:28:35.686 6261-6357/? I/Finsky: [2263] ghj.e(3): XPF:Removing listener for user UserHandle{0} and listener 58165368 2022-02-21 11:28:35.695 15481-5573/? I/RealtimeCacheCleanup: Beginning Realtime garbage collection. 2022-02-21 11:28:35.695 15481-4718/? W/Icing: No valid account for uploading user actions 2022-02-21 11:28:35.698 15481-5573/? I/RealtimeCacheCleanup: Finished Realtime garbage collection. 2022-02-21 11:28:35.707 15481-4718/? I/Icing: Usage reports ok 0, Failed Usage reports 0, indexed 0, rejected 0 2022-02-21 11:28:35.712 525-6733/? I/PackageManagerShellCommandDataLoader-jni: Stop signal received. Sending exit command (remaining bytes: 0). 2022-02-21 11:28:35.715 525-579/? I/PackageManager: Integrity check passed for file:///data/app/vmdl1340592677.tmp 2022-02-21 11:28:35.721 15481-4718/? I/Icing: Indexing com.google.android.gms-apps from com.google.android.gms 2022-02-21 11:28:35.722 180-180/? I/incfs-mounts: [incfs] Loaded incremental-fs mount info: 1 instances, 2 mount points 2022-02-21 11:28:35.723 525-579/? I/incfs-mounts: [incfs] Loaded incremental-fs mount info: 1 instances, 3 mount points 2022-02-21 11:28:35.724 525-579/? I/IncrementalService: Removing bind point /data/app/vmdl1340592677.tmp for storage 89 2022-02-21 11:28:35.724 180-180/? W/incfs: IncFs_Unmount: umount(force) failed, detaching '/data/app/vmdl1340592677.tmp': Device or resource busy 2022-02-21 11:28:35.726 15481-4718/? I/Icing: Indexing done com.google.android.gms-apps 2022-02-21 11:28:35.727 525-579/? D/CompatibilityChangeReporter: Compat change id reported: 135549675; UID 10218; state: DISABLED 2022-02-21 11:28:35.755 525-579/? V/BackupManagerService: [UserID:0] restoreAtInstall pkg=io.appium.espressoserver.test token=26 restoreSet=0 2022-02-21 11:28:35.755 525-579/? V/BackupManagerService: [UserID:0] Finishing install immediately 2022-02-21 11:28:35.756 525-579/? I/AppsFilter: interaction: PackageSetting{5cddf97 io.appium.uiautomator2.server.test/10190} -> PackageSetting{8efdce6 io.appium.espressoserver.test/10218} BLOCKED 2022-02-21 11:28:35.756 525-579/? I/AppsFilter: interaction: PackageSetting{323bd8f io.appium.uiautomator2.server/10189} -> PackageSetting{8efdce6 io.appium.espressoserver.test/10218} BLOCKED 2022-02-21 11:28:35.756 525-579/? I/AppsFilter: interaction: PackageSetting{eca3fbc io.appium.settings/10154} -> PackageSetting{8efdce6 io.appium.espressoserver.test/10218} BLOCKED 2022-02-21 11:28:35.757 525-579/? I/IncrementalService: Removing bind point /data/app/vmdl1340592677.tmp for storage 89 2022-02-21 11:28:35.758 5173-27212/? I/abb: oneway function results will be dropped but finished with status OK and parcel size 4 2022-02-21 11:28:35.761 1311-1311/? I/MediaProvider: Invalidating LocalCallingIdentity cache for package io.appium.espressoserver.test. Reason: package android.intent.action.PACKAGE_ADDED 2022-02-21 11:28:35.754 525-525/? W/Binder:525_2: type=1400 audit(0.0:3588): avc: denied { getopt } for scontext=u:r:system_server:s0 tcontext=u:r:shell:s0 tclass=unix_stream_socket permissive=0 2022-02-21 11:28:35.776 525-525/? I/Telecom: DefaultDialerCache: Refreshing default dialer for user 0: now com.android.dialer: DDC.oR@ATA 2022-02-21 11:28:35.778 5195-5216/? I/PermissionControllerServiceImpl: Updating user sensitive for uid 10218 2022-02-21 11:28:35.785 525-609/? I/InputReader: Reconfiguring input devices, changes=KEYBOARD_LAYOUTS | 2022-02-21 11:28:35.788 6261-6693/? I/Finsky: [2295] ijf.run(33): Wrote row to frosting DB: 533 2022-02-21 11:28:35.793 525-525/? V/BackupManagerConstants: getFullBackupIntervalMilliseconds(...) returns 86400000 2022-02-21 11:28:35.793 525-525/? V/BackupManagerConstants: getFullBackupRequiredNetworkType(...) returns 2 2022-02-21 11:28:35.793 525-525/? V/BackupManagerConstants: getFullBackupRequireCharging(...) returns true 2022-02-21 11:28:35.797 6261-6261/? I/Finsky: [2] xed.c(3): Do not start WearSupportService due to Wear service optimization 2022-02-21 11:28:35.798 6261-6706/? I/Finsky: [2304] fde.accept(35): Asset module storage cleared for package io.appium.espressoserver.test. 2022-02-21 11:28:35.798 6261-6710/? I/Finsky: [2305] ue.invoke(43): [ContentSync] finished, scheduled=false 2022-02-21 11:28:35.799 6261-6261/? I/Finsky: [2] rja.a(8): Clearing split related stale data. 2022-02-21 11:28:35.821 6261-6693/? I/Finsky: [2295] ijf.run(33): Wrote row to frosting DB: 534 2022-02-21 11:28:35.821 1090-6705/? W/GCM: Unexpected forwarded intent: Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 pkg=com.google.android.gms cmp=com.google.android.gms/.chimera.PersistentIntentOperationService (has extras) } 2022-02-21 11:28:35.821 1090-6714/? I/FontLog: Package io.appium.espressoserver.test has no metadata [CONTEXT service_id=132 ] 2022-02-21 11:28:35.822 1090-6716/? W/GCM: Unexpected forwarded intent: Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 pkg=com.google.android.gms cmp=com.google.android.gms/.chimera.PersistentIntentOperationService (has extras) } 2022-02-21 11:28:35.823 857-857/? D/CarrierSvcBindHelper: No carrier app for: 0 2022-02-21 11:28:35.825 15481-6720/? I/Auth: [SupervisedAccountIntentOperation] onHandleIntent(): android.intent.action.PACKAGE_ADDED 2022-02-21 11:28:35.826 15481-6720/? I/BlockstoreStorage: Clearing Blockstore Data for package io.appium.espressoserver.test [CONTEXT service_id=258 ] 2022-02-21 11:28:35.827 15481-6720/? I/BlockstoreStorage: No metadata found. Skipping deletion. [CONTEXT service_id=258 ] 2022-02-21 11:28:35.827 15481-6720/? I/Dck: doesDeviceHaveSupportedWirelessCapabilities: wccSysProp:0, wccMendel:1, deviceWccOverride:false [CONTEXT service_id=289 ] 2022-02-21 11:28:35.828 15481-15481/? D/BoundBrokerSvc: onBind: Intent { act=com.google.android.gms.common.BIND_SHARED_PREFS pkg=com.google.android.gms } 2022-02-21 11:28:35.828 15481-15481/? D/BoundBrokerSvc: Loading bound service for intent: Intent { act=com.google.android.gms.common.BIND_SHARED_PREFS pkg=com.google.android.gms } 2022-02-21 11:28:35.831 15481-15481/? D/BoundBrokerSvc: onUnbind: Intent { act=com.google.android.gms.common.BIND_SHARED_PREFS pkg=com.google.android.gms } 2022-02-21 11:28:35.831 15481-6720/? I/Dck: isDckModuleEligible: isAtLeastR:true, hasWccSupport:false, downloadAllowed:false, featureEnabled:true [CONTEXT service_id=289 ] 2022-02-21 11:28:35.832 15481-6720/? W/Dck: Dck module not eligible for asynchronous downloading [CONTEXT service_id=289 ] 2022-02-21 11:28:35.852 857-857/? D/CarrierConfigLoader: mHandler: 9 phoneId: 0 2022-02-21 11:28:35.854 5642-5674/? I/ProvidersCache: Provider returned no roots. Possibly naughty: com.google.android.apps.docs.storage 2022-02-21 11:28:35.860 1090-27375/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:35.865 15481-3960/? I/Icing: Indexing com.google.android.gms-apps from com.google.android.gms 2022-02-21 11:28:35.868 15481-3960/? I/Icing: Indexing done com.google.android.gms-apps 2022-02-21 11:28:35.870 1090-27375/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:35.871 1090-27375/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:35.880 380-380/? E/adbd: failed to connect to socket 'tcp:6791': Connection refused 2022-02-21 11:28:35.917 525-525/? W/Looper: Slow dispatch took 141ms main h=android.app.ActivityThread$H c=android.app.-$$Lambda$LoadedApk$ReceiverDispatcher$Args$_BumDX2UKsnxLVrE6UJsJZkotuA@3b5e61d m=0 2022-02-21 11:28:35.917 525-525/? I/AppsFilter: interaction: PackageSetting{5cddf97 io.appium.uiautomator2.server.test/10190} -> PackageSetting{8efdce6 io.appium.espressoserver.test/10218} BLOCKED 2022-02-21 11:28:35.917 525-525/? I/AppsFilter: interaction: PackageSetting{323bd8f io.appium.uiautomator2.server/10189} -> PackageSetting{8efdce6 io.appium.espressoserver.test/10218} BLOCKED 2022-02-21 11:28:35.917 525-525/? I/AppsFilter: interaction: PackageSetting{eca3fbc io.appium.settings/10154} -> PackageSetting{8efdce6 io.appium.espressoserver.test/10218} BLOCKED 2022-02-21 11:28:35.903 380-380/? E/adbd: failed to connect to socket 'tcp:6791': Connection refused 2022-02-21 11:28:35.923 525-609/? I/InputReader: Reconfiguring input devices, changes=KEYBOARD_LAYOUTS | 2022-02-21 11:28:35.945 525-534/? I/system_server: Background concurrent copying GC freed 156117(8285KB) AllocSpace objects, 47(2648KB) LOS objects, 49% free, 18MB/37MB, paused 72us total 187.536ms 2022-02-21 11:28:35.955 1090-6705/? I/Fitness: OnPackageChangedOperation got intent: Intent { act=android.intent.action.PACKAGE_CHANGED dat=package:io.appium.espressoserver.test flg=0x5000010 pkg=com.google.android.gms cmp=com.google.android.gms/.chimera.PersistentIntentOperationService (has extras) } [CONTEXT service_id=17 ] 2022-02-21 11:28:35.968 525-525/? I/Telecom: DefaultDialerCache: Refreshing default dialer for user 0: now com.android.dialer: DDC.oR@ATM 2022-02-21 11:28:35.970 857-857/? D/CarrierSvcBindHelper: No carrier app for: 0 2022-02-21 11:28:35.972 1090-6705/? I/Fitness: FitCleanupIntentOperation received Intent android.intent.action.PACKAGE_CHANGED [CONTEXT service_id=17 ] 2022-02-21 11:28:35.977 1090-3705/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:35.984 1090-3705/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:35.987 15481-4718/? I/Icing: Indexing com.google.android.gms-apps from com.google.android.gms 2022-02-21 11:28:35.988 15481-4718/? I/Icing: Indexing done com.google.android.gms-apps 2022-02-21 11:28:35.990 1090-3705/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:35.998 5642-5674/? I/ProvidersCache: Provider returned no roots. Possibly naughty: com.google.android.apps.docs.storage 2022-02-21 11:28:36.008 6743-6743/? D/AndroidRuntime: >>>>>> START com.android.internal.os.RuntimeInit uid 2000 <<<<<< 2022-02-21 11:28:36.009 5195-5214/? I/PermissionControllerServiceImpl: Updating user sensitive for uid 10218 2022-02-21 11:28:36.013 6743-6743/? E/libc: Access denied finding property "persist.device_config.runtime_native_boot.profilebootclasspath" 2022-02-21 11:28:36.013 6743-6743/? E/libc: Access denied finding property "persist.device_config.runtime_native_boot.enable_apex_image" 2022-02-21 11:28:36.013 6743-6743/? I/AndroidRuntime: Using default boot image 2022-02-21 11:28:36.013 6743-6743/? E/libc: Access denied finding property "persist.device_config.runtime_native_boot.disable_lock_profiling" 2022-02-21 11:28:36.013 6743-6743/? I/AndroidRuntime: Leaving lock profiling enabled 2022-02-21 11:28:36.013 6743-6743/? E/libc: Access denied finding property "persist.device_config.runtime_native_boot.enable_generational_cc" 2022-02-21 11:28:36.016 5642-5656/? W/oid.documentsu: Reducing the number of considered missed Gc histogram windows from 115 to 100 2022-02-21 11:28:36.084 6743-6743/? D/app_process: Time zone APEX ICU file found: /apex/com.android.tzdata/etc/icu/icu_tzdata.dat 2022-02-21 11:28:36.084 6743-6743/? D/app_process: I18n APEX ICU file found: /apex/com.android.i18n/etc/icu/icudt66l.dat 2022-02-21 11:28:36.088 6743-6743/? W/app_process: Unexpected CPU variant for X86 using defaults: x86 2022-02-21 11:28:36.089 6743-6743/? I/app_process: The ClassLoaderContext is a special shared library. 2022-02-21 11:28:36.099 6743-6743/? W/app_process: JNI RegisterNativeMethods: attempt to register 0 native methods for android.media.AudioAttributes 2022-02-21 11:28:36.103 6743-6743/? D/AndroidRuntime: Calling main entry com.android.commands.am.Am 2022-02-21 11:28:36.107 525-4202/? I/ActivityManager: Force stopping com.example.jetpackcomposeplayground appid=10215 user=0: start instr 2022-02-21 11:28:36.108 525-4202/? D/CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10215; state: DISABLED 2022-02-21 11:28:36.109 525-563/? D/CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10215; state: ENABLED 2022-02-21 11:28:36.117 293-293/? D/Zygote: Forked child process 6760 2022-02-21 11:28:36.118 525-563/? I/ActivityManager: Start proc 6760:com.example.jetpackcomposeplayground/u0a215 for added application com.example.jetpackcomposeplayground 2022-02-21 11:28:36.123 6760-6760/? I/mposeplaygroun: Late-enabling -Xcheck:jni 2022-02-21 11:28:36.138 6760-6760/? I/mposeplaygroun: Unquickening 12 vdex files! 2022-02-21 11:28:36.139 6760-6760/? W/mposeplaygroun: Unexpected CPU variant for X86 using defaults: x86 2022-02-21 11:28:36.142 380-408/? I/adbd: jdwp connection from 6760 2022-02-21 11:28:36.169 6760-6760/com.example.jetpackcomposeplayground I/mposeplaygroun: The ClassLoaderContext is a special shared library. 2022-02-21 11:28:36.171 6760-6760/com.example.jetpackcomposeplayground I/chatty: uid=10215(com.example.jetpackcomposeplayground) identical 1 line 2022-02-21 11:28:36.172 6760-6760/com.example.jetpackcomposeplayground I/mposeplaygroun: The ClassLoaderContext is a special shared library. 2022-02-21 11:28:36.244 15481-15481/? D/BoundBrokerSvc: onBind: Intent { act=com.google.android.gms.common.BIND_SHARED_PREFS pkg=com.google.android.gms } 2022-02-21 11:28:36.244 15481-15481/? D/BoundBrokerSvc: Loading bound service for intent: Intent { act=com.google.android.gms.common.BIND_SHARED_PREFS pkg=com.google.android.gms } 2022-02-21 11:28:36.245 15481-15481/? D/BoundBrokerSvc: onUnbind: Intent { act=com.google.android.gms.common.BIND_SHARED_PREFS pkg=com.google.android.gms } 2022-02-21 11:28:36.252 1311-4256/? I/MediaProvider: Begin Intent { act=android.intent.action.PACKAGE_FULLY_REMOVED dat=package:io.appium.espressoserver.test flg=0x5000010 cmp=com.google.android.providers.media.module/com.android.providers.media.MediaService (has extras) } 2022-02-21 11:28:36.253 1311-4256/? I/MediaProvider: End Intent { act=android.intent.action.PACKAGE_FULLY_REMOVED dat=package:io.appium.espressoserver.test flg=0x5000010 cmp=com.google.android.providers.media.module/com.android.providers.media.MediaService (has extras) } 2022-02-21 11:28:36.262 525-3905/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.packageinstaller/com.android.packageinstaller.PackageInstalledReceiver 2022-02-21 11:28:36.263 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.android.vending/com.google.android.finsky.packagemanager.impl.PackageMonitorReceiverImpl$RegisteredReceiver 2022-02-21 11:28:36.263 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.gms/.games.chimera.GamesSystemBroadcastReceiverProxy 2022-02-21 11:28:36.263 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.gms/.gass.chimera.PackageChangeBroadcastReceiver 2022-02-21 11:28:36.263 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver 2022-02-21 11:28:36.263 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.googlequicksearchbox/com.google.android.apps.gsa.googlequicksearchbox.GelStubAppWatcher 2022-02-21 11:28:36.263 525-562/? W/BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.PACKAGE_ADDED dat=package:io.appium.espressoserver.test flg=0x4000010 (has extras) } to com.google.android.ims/.receivers.RcsAutoStartReceiver 2022-02-21 11:28:36.266 6261-6261/? I/Finsky: [2] nyl.i(0): PackageMonitorReceiverImpl - Received: android.intent.action.PACKAGE_CHANGED, [8isIk55MHOSvSL4G9NjEPBtem7gYUdqMEtfvpVWwS8Y] 2022-02-21 11:28:36.266 6261-6261/? I/Finsky: [2] nzb.n(8): Invalidating cached PackageState for io.appium.espressoserver.test 2022-02-21 11:28:36.275 6261-6693/? I/Finsky: [2295] ijf.run(33): Wrote row to frosting DB: 535 2022-02-21 11:28:36.283 6261-6693/? I/Finsky: [2295] ijf.run(33): Wrote row to frosting DB: 536 2022-02-21 11:28:36.284 1090-6718/? I/Fitness: OnPackageChangedOperation got intent: Intent { act=android.intent.action.PACKAGE_CHANGED dat=package:io.appium.espressoserver.test flg=0x5000010 pkg=com.google.android.gms cmp=com.google.android.gms/.chimera.PersistentIntentOperationService (has extras) } [CONTEXT service_id=17 ] 2022-02-21 11:28:36.294 1090-6718/? I/Fitness: FitCleanupIntentOperation received Intent android.intent.action.PACKAGE_CHANGED [CONTEXT service_id=17 ] 2022-02-21 11:28:36.297 1090-27375/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:36.301 15481-3960/? I/Icing: Indexing com.google.android.gms-apps from com.google.android.gms 2022-02-21 11:28:36.302 15481-3960/? I/Icing: Indexing done com.google.android.gms-apps 2022-02-21 11:28:36.303 1090-27375/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:36.304 1090-27375/? W/ChimeraUtils: Module com.google.android.gms.nearby_en has empty metadata display_name_string_id 2022-02-21 11:28:36.409 380-380/? E/adbd: failed to connect to socket 'tcp:6791': Connection refused 2022-02-21 11:28:36.503 525-551/? I/RoleManagerService: Granting default roles... 2022-02-21 11:28:36.628 6760-6760/com.example.jetpackcomposeplayground D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar 2022-02-21 11:28:36.628 6760-6760/com.example.jetpackcomposeplayground D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar 2022-02-21 11:28:36.629 6760-6760/com.example.jetpackcomposeplayground I/mposeplaygroun: The ClassLoaderContext is a special shared library. 2022-02-21 11:28:36.630 6760-6760/com.example.jetpackcomposeplayground D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar 2022-02-21 11:28:36.630 6760-6760/com.example.jetpackcomposeplayground D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar 2022-02-21 11:28:36.631 6760-6760/com.example.jetpackcomposeplayground I/mposeplaygroun: The ClassLoaderContext is a special shared library. 2022-02-21 11:28:36.633 6760-6760/com.example.jetpackcomposeplayground I/chatty: uid=10215(com.example.jetpackcomposeplayground) identical 2 lines 2022-02-21 11:28:36.635 6760-6760/com.example.jetpackcomposeplayground I/mposeplaygroun: The ClassLoaderContext is a special shared library. 2022-02-21 11:28:36.911 380-380/? E/adbd: failed to connect to socket 'tcp:6791': Connection refused 2022-02-21 11:28:37.051 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/app/Instrumentation;->execStartActivity(Landroid/content/Context;Landroid/os/IBinder;Landroid/os/IBinder;Landroid/app/Activity;Landroid/content/Intent;ILandroid/os/Bundle;)Landroid/app/Instrumentation$ActivityResult; (greylist, linking, allowed) 2022-02-21 11:28:37.051 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/app/Instrumentation;->execStartActivity(Landroid/content/Context;Landroid/os/IBinder;Landroid/os/IBinder;Ljava/lang/String;Landroid/content/Intent;ILandroid/os/Bundle;)Landroid/app/Instrumentation$ActivityResult; (greylist, linking, allowed) 2022-02-21 11:28:37.055 6760-6760/com.example.jetpackcomposeplayground D/NetworkSecurityConfig: No Network Security Config specified, using platform default 2022-02-21 11:28:37.055 6760-6760/com.example.jetpackcomposeplayground D/NetworkSecurityConfig: No Network Security Config specified, using platform default 2022-02-21 11:28:37.060 6760-6760/com.example.jetpackcomposeplayground I/MonitoringInstr: Instrumentation started! 2022-02-21 11:28:37.066 6760-6760/com.example.jetpackcomposeplayground I/MonitoringInstr: No JSBridge. 2022-02-21 11:28:37.072 6760-6784/com.example.jetpackcomposeplayground I/UsageTrackerFacilitator: Usage tracking disabled 2022-02-21 11:28:37.074 6760-6784/com.example.jetpackcomposeplayground I/TestRequestBuilder: Scanning classpath to find tests in paths [/data/app/~~AmDb55EiZEPpBgBmmcvMOQ==/io.appium.espressoserver.test-mayV_Onf9AQxloMmtoF82w==/base.apk] 2022-02-21 11:28:37.075 6760-6784/com.example.jetpackcomposeplayground W/mposeplaygroun: Opening an oat file without a class loader. Are you using the deprecated DexFile APIs? 2022-02-21 11:28:37.416 380-380/? E/adbd: failed to connect to socket 'tcp:6791': Connection refused 2022-02-21 11:28:37.669 525-572/? I/incfs-mounts: [incfs] Loaded incremental-fs mount info: 1 instances, 2 mount points 2022-02-21 11:28:37.682 6760-6784/com.example.jetpackcomposeplayground E/TestLoader: Could not find class: com.sun.jna.platform.dnd.DragHandler 2022-02-21 11:28:37.682 6760-6784/com.example.jetpackcomposeplayground E/TestLoader: Could not find class: com.sun.jna.platform.dnd.DropHandler 2022-02-21 11:28:37.844 6760-6784/com.example.jetpackcomposeplayground E/TestLoader: Could not find class: kotlinx.coroutines.debug.CoroutinesBlockHoundIntegration 2022-02-21 11:28:37.845 6760-6784/com.example.jetpackcomposeplayground E/TestLoader: Could not find class: kotlinx.coroutines.debug.junit5.CoroutinesTimeoutExtension 2022-02-21 11:28:37.855 6760-6784/com.example.jetpackcomposeplayground E/TestLoader: Could not find class: kotlinx.coroutines.repackaged.net.bytebuddy.agent.builder.ResettableClassFileTransformer 2022-02-21 11:28:37.859 6760-6784/com.example.jetpackcomposeplayground E/TestLoader: Could not find class: kotlinx.coroutines.repackaged.net.bytebuddy.dynamic.loading.NoOpClassFileTransformer 2022-02-21 11:28:37.894 6760-6784/com.example.jetpackcomposeplayground D/TestExecutor: Adding listener androidx.test.internal.runner.listener.LogRunListener 2022-02-21 11:28:37.894 6760-6784/com.example.jetpackcomposeplayground D/TestExecutor: Adding listener androidx.test.internal.runner.listener.InstrumentationResultPrinter 2022-02-21 11:28:37.894 6760-6784/com.example.jetpackcomposeplayground D/TestExecutor: Adding listener androidx.test.internal.runner.listener.ActivityFinisherRunListener 2022-02-21 11:28:37.895 6760-6784/com.example.jetpackcomposeplayground I/TestRunner: run started: 1 tests 2022-02-21 11:28:37.919 380-380/? E/adbd: failed to connect to socket 'tcp:6791': Connection refused 2022-02-21 11:28:37.921 6760-6784/com.example.jetpackcomposeplayground I/TestRunner: started: startEspressoServer(io.appium.espressoserver.EspressoServerRunnerTest) 2022-02-21 11:28:37.950 6760-6784/com.example.jetpackcomposeplayground I/appium: Running Appium Espresso Server at port 6791 2022-02-21 11:28:37.952 6760-6784/com.example.jetpackcomposeplayground D/appium: Generating routes 2022-02-21 11:28:38.427 6760-6788/com.example.jetpackcomposeplayground D/appium: Started processing GET request for '/status' 2022-02-21 11:28:38.428 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route definition: class io.appium.espressoserver.lib.http.RouteDefinition 2022-02-21 11:28:38.428 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route handler: class io.appium.espressoserver.lib.handlers.Status 2022-02-21 11:28:38.443 6760-6788/com.example.jetpackcomposeplayground I/appium: Executing Status handler 2022-02-21 11:28:38.444 6760-6788/com.example.jetpackcomposeplayground D/appium: Finished processing GET request for '/status' 2022-02-21 11:28:38.444 6760-6788/com.example.jetpackcomposeplayground I/appium: Responding to server with value: null 2022-02-21 11:28:38.466 6760-6788/com.example.jetpackcomposeplayground D/appium: Started processing POST request for '/session' 2022-02-21 11:28:38.466 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route definition: class io.appium.espressoserver.lib.http.RouteDefinition 2022-02-21 11:28:38.466 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route handler: class io.appium.espressoserver.lib.handlers.CreateSession 2022-02-21 11:28:38.467 6760-6788/com.example.jetpackcomposeplayground D/appium: Got raw post data: {"capabilities":{"firstMatch":[{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","deviceName":"emulator-5556","app":"/h… 2022-02-21 11:28:38.471 6760-6788/com.example.jetpackcomposeplayground I/appium: Executing CreateSession handler 2022-02-21 11:28:38.475 6760-6788/com.example.jetpackcomposeplayground I/appium: Starting activity 'com.example.jetpackcompose.core.MainActivity' with default options: {action=ACTION_MAIN, flags=ACTIVITY_NEW_TASK, className=com.example.jetpackcompose.core.MainActivity} 2022-02-21 11:28:38.480 525-5080/? I/ActivityTaskManager: START u0 {act=ACTION_MAIN flg=0x14000000 cmp=com.example.jetpackcomposeplayground/com.example.jetpackcompose.core.MainActivity} from uid 10215 2022-02-21 11:28:38.481 525-554/? D/EventSequenceValidator: inc AccIntentStartedEvents to 2 2022-02-21 11:28:38.534 525-541/? W/InputReader: Device virtio_input_multi_touch_10 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.534 525-541/? W/InputReader: Device virtio_input_multi_touch_4 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.534 525-541/? W/InputReader: Device virtio_input_multi_touch_11 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.534 525-541/? W/InputReader: Device virtio_input_multi_touch_6 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.534 525-541/? W/InputReader: Device virtio_input_multi_touch_3 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.534 525-541/? W/InputReader: Device virtio_input_multi_touch_5 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.536 525-541/? W/InputReader: Device virtio_input_multi_touch_2 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.536 525-541/? W/InputReader: Device virtio_input_multi_touch_8 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.536 525-541/? W/InputReader: Device virtio_input_multi_touch_9 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.540 525-541/? W/InputReader: Device virtio_input_multi_touch_7 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_10 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_4 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_11 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_6 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_3 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_5 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_2 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.546 525-541/? W/InputReader: Device virtio_input_multi_touch_8 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.547 525-541/? W/InputReader: Device virtio_input_multi_touch_9 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.547 525-541/? W/InputReader: Device virtio_input_multi_touch_7 is associated with display ADISPLAY_ID_NONE. 2022-02-21 11:28:38.606 6760-6792/com.example.jetpackcomposeplayground D/libEGL: loaded /vendor/lib/egl/libEGL_emulation.so 2022-02-21 11:28:38.610 6760-6792/com.example.jetpackcomposeplayground D/libEGL: loaded /vendor/lib/egl/libGLESv1_CM_emulation.so 2022-02-21 11:28:38.610 6760-6760/com.example.jetpackcomposeplayground D/LifecycleMonitor: Lifecycle status change: com.example.jetpackcompose.core.MainActivity@600293c in: PRE_ON_CREATE 2022-02-21 11:28:38.618 6760-6792/com.example.jetpackcomposeplayground D/libEGL: loaded /vendor/lib/egl/libGLESv2_emulation.so 2022-02-21 11:28:38.619 309-309/? D/goldfish-address-space: claimShared: Ask to claim region [0x3f0000000 0x3f0965000] 2022-02-21 11:28:38.666 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/view/View;->computeFitSystemWindows(Landroid/graphics/Rect;Landroid/graphics/Rect;)Z (greylist, reflection, allowed) 2022-02-21 11:28:38.666 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/view/ViewGroup;->makeOptionalFitsSystemWindows()V (greylist, reflection, allowed) 2022-02-21 11:28:38.732 6760-6760/com.example.jetpackcomposeplayground D/LifecycleMonitor: Lifecycle status change: com.example.jetpackcompose.core.MainActivity@600293c in: CREATED 2022-02-21 11:28:38.735 6760-6760/com.example.jetpackcomposeplayground D/LifecycleMonitor: Lifecycle status change: com.example.jetpackcompose.core.MainActivity@600293c in: STARTED 2022-02-21 11:28:38.736 6760-6760/com.example.jetpackcomposeplayground D/LifecycleMonitor: Lifecycle status change: com.example.jetpackcompose.core.MainActivity@600293c in: RESUMED 2022-02-21 11:28:38.773 6760-6790/com.example.jetpackcomposeplayground D/HostConnection: HostConnection::get() New Host Connection established 0xf74e4740, tid 6790 2022-02-21 11:28:38.777 6760-6790/com.example.jetpackcomposeplayground D/HostConnection: HostComposition ext ANDROID_EMU_CHECKSUM_HELPER_v1 ANDROID_EMU_native_sync_v2 ANDROID_EMU_native_sync_v3 ANDROID_EMU_native_sync_v4 ANDROID_EMU_dma_v1 ANDROID_EMU_direct_mem ANDROID_EMU_host_composition_v1 ANDROID_EMU_host_composition_v2 ANDROID_EMU_vulkan ANDROID_EMU_deferred_vulkan_commands ANDROID_EMU_vulkan_null_optional_strings ANDROID_EMU_vulkan_create_resources_with_requirements ANDROID_EMU_YUV_Cache ANDROID_EMU_vulkan_ignored_handles ANDROID_EMU_has_shared_slots_host_memory_allocator ANDROID_EMU_vulkan_free_memory_sync ANDROID_EMU_vulkan_shader_float16_int8 ANDROID_EMU_vulkan_async_queue_submit ANDROID_EMU_sync_buffer_data ANDROID_EMU_read_color_buffer_dma GL_OES_EGL_image_external_essl3 GL_OES_vertex_array_object GL_KHR_texture_compression_astc_ldr ANDROID_EMU_host_side_tracing ANDROID_EMU_gles_max_version_3_0 2022-02-21 11:28:38.784 178-178/? I/hwservicemanager: getTransport: Cannot find entry android.hardware.configstore@1.0::ISurfaceFlingerConfigs/default in either framework or device manifest. 2022-02-21 11:28:38.784 6760-6790/com.example.jetpackcomposeplayground W/OpenGLRenderer: Failed to choose config with EGL_SWAP_BEHAVIOR_PRESERVED, retrying without... 2022-02-21 11:28:38.795 6760-6790/com.example.jetpackcomposeplayground D/EGL_emulation: eglCreateContext: 0xf74c55d0: maj 3 min 0 rcv 3 2022-02-21 11:28:38.802 6760-6790/com.example.jetpackcomposeplayground D/EGL_emulation: eglMakeCurrent: 0xf74c55d0: ver 3 0 (tinfo 0xf7830fd0) (first time) 2022-02-21 11:28:38.811 309-309/? D/goldfish-address-space: claimShared: Ask to claim region [0x3f12ca000 0x3f1c2f000] 2022-02-21 11:28:38.813 178-178/? I/hwservicemanager: getTransport: Cannot find entry android.hardware.graphics.mapper@4.0::IMapper/default in either framework or device manifest. 2022-02-21 11:28:38.813 6760-6790/com.example.jetpackcomposeplayground I/Gralloc4: mapper 4.x is not supported 2022-02-21 11:28:38.814 6760-6790/com.example.jetpackcomposeplayground D/HostConnection: createUnique: call 2022-02-21 11:28:38.814 6760-6790/com.example.jetpackcomposeplayground D/HostConnection: HostConnection::get() New Host Connection established 0xf74c6050, tid 6790 2022-02-21 11:28:38.815 6760-6790/com.example.jetpackcomposeplayground D/goldfish-address-space: allocate: Ask for block of size 0x100 2022-02-21 11:28:38.815 6760-6790/com.example.jetpackcomposeplayground D/goldfish-address-space: allocate: ioctl allocate returned offset 0x3efffe000 size 0x2000 2022-02-21 11:28:38.851 6760-6790/com.example.jetpackcomposeplayground D/HostConnection: HostComposition ext ANDROID_EMU_CHECKSUM_HELPER_v1 ANDROID_EMU_native_sync_v2 ANDROID_EMU_native_sync_v3 ANDROID_EMU_native_sync_v4 ANDROID_EMU_dma_v1 ANDROID_EMU_direct_mem ANDROID_EMU_host_composition_v1 ANDROID_EMU_host_composition_v2 ANDROID_EMU_vulkan ANDROID_EMU_deferred_vulkan_commands ANDROID_EMU_vulkan_null_optional_strings ANDROID_EMU_vulkan_create_resources_with_requirements ANDROID_EMU_YUV_Cache ANDROID_EMU_vulkan_ignored_handles ANDROID_EMU_has_shared_slots_host_memory_allocator ANDROID_EMU_vulkan_free_memory_sync ANDROID_EMU_vulkan_shader_float16_int8 ANDROID_EMU_vulkan_async_queue_submit ANDROID_EMU_sync_buffer_data ANDROID_EMU_read_color_buffer_dma GL_OES_EGL_image_external_essl3 GL_OES_vertex_array_object GL_KHR_texture_compression_astc_ldr ANDROID_EMU_host_side_tracing ANDROID_EMU_gles_max_version_3_0 2022-02-21 11:28:38.853 309-309/? D/goldfish-address-space: claimShared: Ask to claim region [0x3f5c32000 0x3f6597000] 2022-02-21 11:28:38.856 309-309/? D/goldfish-address-space: claimShared: Ask to claim region [0x3f4000000 0x3f4965000] 2022-02-21 11:28:38.979 525-554/? D/EventSequenceValidator: dec AccIntentStartedEvents to 1 2022-02-21 11:28:38.979 525-561/? D/ArtManagerInternalImpl: /data/misc/iorapd/com.example.jetpackcomposeplayground/1/com.example.jetpackcompose.core.MainActivity/compiled_traces/compiled_trace.pb doesn't exist 2022-02-21 11:28:38.980 525-561/? I/ActivityTaskManager: Displayed com.example.jetpackcomposeplayground/com.example.jetpackcompose.core.MainActivity: +496ms 2022-02-21 11:28:39.032 6760-6788/com.example.jetpackcomposeplayground D/appium: Starting toast notification listener 2022-02-21 11:28:39.069 1912-6796/? I/PBSessionCacheImpl: Deleted sessionId[8410709852807675] from persistence. 2022-02-21 11:28:39.075 6760-6788/com.example.jetpackcomposeplayground D/appium: Original listener: null 2022-02-21 11:28:39.075 6760-6788/com.example.jetpackcomposeplayground D/appium: Finished processing POST request for '/session' 2022-02-21 11:28:39.075 6760-6788/com.example.jetpackcomposeplayground I/appium: Responding to server with value: io.appium.espressoserver.lib.model.GlobalSession@b264ba5 2022-02-21 11:28:39.150 1912-1962/? I/A: NGA disabled since it's running Panthera and at least one a11y feature is on. 2022-02-21 11:28:39.150 1912-1962/? I/A: Nga state changed to DISABLED 2022-02-21 11:28:39.153 1912-1972/? W/SearchServiceCore: Abort, client detached. 2022-02-21 11:28:39.163 1667-1910/? I/A: onIsEnabledChanged, isEnabled: false 2022-02-21 11:28:39.163 1667-1685/? I/A: [Memory] eligibility: StashEligibility{4} 2022-02-21 11:28:39.165 1667-1910/? W/A: Disposing empty manager. Did you forgot to subscribe observables? 2022-02-21 11:28:39.165 1667-1910/? W/A: Disposing empty manager. Did you forgot to subscribe observables? 2022-02-21 11:28:39.166 1667-1910/? I/A: onOpaVisibilityChanged: false 2022-02-21 11:28:39.173 1667-1910/? I/A: Setting session to type: NO_SESSION 2022-02-21 11:28:39.180 1667-1910/? I/A: setSysUiConfiguration, isAvailable: false 2022-02-21 11:28:39.182 1667-1910/? W/A: Disposing empty manager. Did you forgot to subscribe observables? 2022-02-21 11:28:39.182 1667-1910/? I/A: onDisabled. Registered: true 2022-02-21 11:28:39.196 6760-6788/com.example.jetpackcomposeplayground D/appium: Started processing GET request for '/session/8b4dfc7a-c32f-4282-89c2-8a268d85dd59/appium/device/info' 2022-02-21 11:28:39.196 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route definition: class io.appium.espressoserver.lib.http.RouteDefinition 2022-02-21 11:28:39.196 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route handler: class io.appium.espressoserver.lib.handlers.GetDeviceInfo 2022-02-21 11:28:39.197 6760-6788/com.example.jetpackcomposeplayground I/appium: Executing GetDeviceInfo handler 2022-02-21 11:28:39.218 6760-6788/com.example.jetpackcomposeplayground D/appium: Finished processing GET request for '/session/8b4dfc7a-c32f-4282-89c2-8a268d85dd59/appium/device/info' 2022-02-21 11:28:39.219 6760-6788/com.example.jetpackcomposeplayground I/appium: Responding to server with value: {realDisplaySize=1080x2280, apiVersion=30, carrierName=Android, platformVersion=11, timeZone=America/Sao_Paulo, model=sdk_gphone_x86, locale=en_US, brand=google, androidId=9ff712771bcdbfd4, manufacturer=Google, displayDensity=440} 2022-02-21 11:28:39.337 6760-6788/com.example.jetpackcomposeplayground D/appium: Started processing POST request for '/session/8b4dfc7a-c32f-4282-89c2-8a268d85dd59/element' 2022-02-21 11:28:39.339 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route definition: class io.appium.espressoserver.lib.http.RouteDefinition 2022-02-21 11:28:39.339 6760-6788/com.example.jetpackcomposeplayground D/appium: Matched route handler: class io.appium.espressoserver.lib.handlers.FindElement 2022-02-21 11:28:39.339 6760-6788/com.example.jetpackcomposeplayground D/appium: Got raw post data: {"using":"xpath","value":"//[@text='Non Existent Text']"} 2022-02-21 11:28:39.342 6760-6788/com.example.jetpackcomposeplayground I/appium: Executing FindElement handler 2022-02-21 11:28:39.363 6760-6788/com.example.jetpackcomposeplayground D/EventInjectionStrategy: Creating injection strategy with input manager. 2022-02-21 11:28:39.363 6760-6788/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/hardware/input/InputManager;->getInstance()Landroid/hardware/input/InputManager; (greylist, reflection, allowed) 2022-02-21 11:28:39.363 6760-6788/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/hardware/input/InputManager;->injectInputEvent(Landroid/view/InputEvent;I)Z (greylist, reflection, allowed) 2022-02-21 11:28:39.363 6760-6788/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden field Landroid/hardware/input/InputManager;->INJECT_INPUT_EVENT_MODE_WAIT_FOR_FINISH:I (greylist, reflection, allowed) 2022-02-21 11:28:39.369 6760-6760/com.example.jetpackcomposeplayground D/IdlingResourceRegistry: All idling resources are idle. 2022-02-21 11:28:39.370 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/os/MessageQueue;->next()Landroid/os/Message; (greylist, reflection, allowed) 2022-02-21 11:28:39.370 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden field Landroid/os/MessageQueue;->mMessages:Landroid/os/Message; (greylist, reflection, allowed) 2022-02-21 11:28:39.370 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/os/Message;->recycleUnchecked()V (greylist, reflection, allowed) 2022-02-21 11:28:39.370 6760-6760/com.example.jetpackcomposeplayground D/IdlingResourceRegistry: All idling resources are idle. 2022-02-21 11:28:39.371 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden method Landroid/view/WindowManagerGlobal;->getInstance()Landroid/view/WindowManagerGlobal; (greylist, reflection, allowed) 2022-02-21 11:28:39.371 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden field Landroid/view/WindowManagerGlobal;->mViews:Ljava/util/ArrayList; (greylist, reflection, allowed) 2022-02-21 11:28:39.371 6760-6760/com.example.jetpackcomposeplayground W/mposeplaygroun: Accessing hidden field Landroid/view/WindowManagerGlobal;->mParams:Ljava/util/ArrayList; (greylist, reflection, allowed) 2022-02-21 11:28:39.373 6760-6760/com.example.jetpackcomposeplayground I/ViewInteraction: Performing 'getting view in application' action on view is a root view. 2022-02-21 11:28:39.396 6760-6788/com.example.jetpackcomposeplayground I/appium: The source XML tree has been fetched in 41ms using ByteArrayOutputStream 2022-02-21 11:28:39.415 6760-6760/com.example.jetpackcomposeplayground D/IdlingResourceRegistry: All idling resources are idle. 2022-02-21 11:28:39.415 6760-6760/com.example.jetpackcomposeplayground D/IdlingResourceRegistry: All idling resources are idle. 2022-02-21 11:28:39.443 6760-6788/com.example.jetpackcomposeplayground I/appium: Responding to server with error: {error=no such element, message=Could not find espresso element with strategy XPATH and selector //[@text='Non Existent Text'], stacktrace=io.appium.espressoserver.lib.handlers.exceptions.NoSuchElementException: Could not find espresso element with strategy XPATH and selector //*[@text='Non Existent Text'] at io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:39) at io.appium.espressoserver.lib.handlers.FindElement.handleEspresso(FindElement.kt:27) at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.invokeStrategy(RequestHandler.kt:35) at io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27) at io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27) at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handleInternal(RequestHandler.kt:29) at io.appium.espressoserver.lib.handlers.FindElement.handleInternal(FindElement.kt:27) at io.appium.espressoserver.lib.handlers.FindElement.handleInternal(FindElement.kt:27) at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handle(RequestHandler.kt:57) at io.appium.espressoserver.lib.handlers.FindElement.handle(FindElement.kt:27) at io.appium.espressoserver.lib.handlers.FindElement.handle(FindElement.kt:27) at io.appium.espressoserver.lib.http.Router.route(Router.kt:229) at io.appium.espressoserver.lib.http.Server.serve(Server.kt:51) at fi.iki.elonen.NanoHTTPD$HTTPSession.execute(NanoHTTPD.java:945) at fi.iki.elonen.NanoHTTPD$ClientHandler.run(NanoHTTPD.java:192) at java.lang.Thread.run(Thread.java:923) } 2022-02-21 11:28:40.684 177-177/? I/servicemanager: Notifying apexservice they have clients: 0 2022-02-21 11:28:40.686 177-177/? I/BpBinder: onLastStrongRef automatically unlinking death recipients: 2022-02-21 11:28:44.026 1194-1309/? I/PeriodicStatsRunner: PeriodicStatsRunner.call():180 call() 2022-02-21 11:28:44.026 1194-1309/? I/PeriodicStatsRunner: PeriodicStatsRunner.call():184 No submit PeriodicStats since input started. 2022-02-21 11:28:44.285 1912-1924/? W/earchbox:searc: Reducing the number of considered missed Gc histogram windows from 112 to 100 2022-02-21 11:28:49.049 1912-1972/? I/WorkerManager: dispose() 2022-02-21 11:28:49.050 1912-1972/? W/A: Queue length for executor EventBus is now 11. Perhaps some tasks are too long, or the pool is too small. 2022-02-21 11:28:50.893 525-3905/? D/WifiNl80211Manager: Scan result ready event 2022-02-21 11:28:50.894 525-3905/? D/WifiNative: Scan result ready event 2022-02-21 11:28:50.906 5300-5300/io.appium.settings D/LocationTracker: Got a location update from Play Services 2022-02-21 11:29:09.414 5343-5369/? I/Finsky:background: [2177] gbv.run(6): Stats for Executor: bgExecutor ihz@7172112[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0] 2022-02-21 11:29:34.863 504-504/? E/netmgr: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:network' service: Invalid argument 2022-02-21 11:29:34.863 504-504/? E/netmgr: Failed to open QEMU pipe 'qemud:network': Invalid argument 2022-02-21 11:29:35.237 506-506/? E/wifi_forwarder: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:wififorward' service: Invalid argument 2022-02-21 11:29:35.237 506-506/? E/wifi_forwarder: RemoteConnection failed to initialize: RemoteConnection failed to open pipe 2022-02-21 11:29:50.910 525-5080/? D/WifiNl80211Manager: Scan result ready event 2022-02-21 11:29:50.911 525-5080/? D/WifiNative: Scan result ready event 2022-02-21 11:29:50.943 5300-5300/io.appium.settings D/LocationTracker: Got a location update from Play Services 2022-02-21 11:30:21.997 1090-4895/? E/WakeLock: GCM_HB_ALARM release without a matched acquire! 2022-02-21 11:30:33.760 15481-15481/? D/BoundBrokerSvc: onUnbind: Intent { act=com.google.android.gms.feedback.internal.IFeedbackService cmp=com.google.android.gms/.chimera.GmsBoundBrokerService } 2022-02-21 11:30:33.779 525-541/? I/ActivityManager: Killing 6325:com.google.process.gapps/u0a108 (adj 985): empty #17 2022-02-21 11:30:33.819 293-293/? I/Zygote: Process 6325 exited due to signal 9 (Killed) 2022-02-21 11:30:33.821 525-564/? I/libprocessgroup: Successfully killed process cgroup uid 10108 pid 6325 in 40ms 2022-02-21 11:30:34.866 504-504/? E/netmgr: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:network' service: Invalid argument 2022-02-21 11:30:34.866 504-504/? E/netmgr: Failed to open QEMU pipe 'qemud:network': Invalid argument 2022-02-21 11:30:35.279 506-506/? E/wifi_forwarder: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:wififorward' service: Invalid argument 2022-02-21 11:30:35.279 506-506/? E/wifi_forwarder: RemoteConnection failed to initialize: RemoteConnection failed to open pipe 2022-02-21 11:30:50.904 525-5080/? D/WifiNl80211Manager: Scan result ready event 2022-02-21 11:30:50.904 525-5080/? D/WifiNative: Scan result ready event 2022-02-21 11:30:50.937 5300-5300/io.appium.settings D/LocationTracker: Got a location update from Play Services 2022-02-21 11:31:11.440 6261-6303/? I/PlayCommon: [2243] abof.k(22): Preparing logs for uploading 2022-02-21 11:31:11.442 6261-6303/? I/PlayCommon: [2243] abof.k(135): Connecting to server for timestamp: https://play.googleapis.com/play/log/timestamp 2022-02-21 11:31:13.394 6261-6303/? W/PlayCommon: [2243] abof.m(1): No account for auth token provided 2022-02-21 11:31:13.395 6261-6303/? I/PlayCommon: [2243] abof.k(169): Connecting to server: https://play.googleapis.com/play/log?format=raw&proto_v2=true 2022-02-21 11:31:13.698 6261-6303/? I/PlayCommon: [2243] abof.k(202): Successfully uploaded logs. 2022-02-21 11:31:34.881 504-504/? E/netmgr: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:network' service: Invalid argument 2022-02-21 11:31:34.881 504-504/? E/netmgr: Failed to open QEMU pipe 'qemud:network': Invalid argument 2022-02-21 11:31:35.284 506-506/? E/wifi_forwarder: qemu_pipe_open_ns:62: Could not connect to the 'pipe:qemud:wififorward' service: Invalid argument 2022-02-21 11:31:35.284 506-506/? E/wifi_forwarder: RemoteConnection failed to initialize: RemoteConnection failed to open pipe

rajdeepv commented 2 years ago

Hi @dmertins if this is only reproducible in Appium 2.0 beta, and not in the previous version, then it is worth raising the issue in https://github.com/appium/appium-espresso-driver/issues

dmertins commented 2 years ago

Thank you Raj! I've opend the issue there.