04-13 17:11:59 D/Configuration: Resolve and download remote files from @Option
04-13 17:11:59 I/TestInvocation: Invocation was started with cmd: cts -m CtsGraphicsTestCases -t android.graphics.cts.SetFrameRateTest
04-13 17:11:59 D/InvocationExecution: Skip linking external directory as FileProperty was set.
04-13 17:11:59 D/RunUtil: Running command [adb, version] with timeout: 2m 0s
04-13 17:11:59 D/TestInvocation: Fetch build duration: 2 ms
04-13 17:11:59 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:00 D/GlobalTestFilter: Setting up global filters
04-13 17:12:00 D/BackgroundDeviceAction: Sleep for 5000 before starting logcat for 0001201904000455.
04-13 17:12:00 I/TestInvocation: Starting invocation for 'cts' with '[ DeviceBuildInfo{bid=9566628, serial=0001201904000455} on device '0001201904000455'] 
04-13 17:12:00 D/FileUtil: Creating temp directory at /tmp/9566628/cts with prefix "inv_"
04-13 17:12:00 D/RunUtil: Running command [chmod, ug+rwx, /tmp/9566628/cts/inv_13386742803945196181] with timeout: 10s
04-13 17:12:00 D/FileSystemLogSaver: Using log file directory /tmp/9566628/cts/inv_13386742803945196181
04-13 17:12:00 D/FileUtil: Creating temp directory at /tmp/9566628/cts/inv_13386742803945196181 with prefix "inv_"
04-13 17:12:00 I/LogFileSaver: Using log file directory /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470
04-13 17:12:00 D/CompatibilityProtoResultReporter: Proto Results Directory: /home/xts/tools/android-cts/tools/../../android-cts/results/2023.04.13_17.11.59/proto
04-13 17:12:00 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/results/2023.04.13_17.11.59/proto with prefix "tmp-proto" suffix ""
04-13 17:12:00 D/CertificationSuiteResultReporter: Initializing result directory
04-13 17:12:00 D/CertificationSuiteResultReporter: Results Directory: /home/xts/tools/android-cts/tools/../../android-cts/results/2023.04.13_17.11.59
04-13 17:12:00 D/CertificationSuiteResultReporter: Created log dir /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59
04-13 17:12:00 D/FileUtil: Creating temp directory at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59 with prefix "inv_"
04-13 17:12:00 I/LogFileSaver: Using log file directory /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284
04-13 17:12:00 D/CompatibilityProtoResultReporter: Proto Results Directory: /home/xts/tools/android-cts/tools/../../android-cts/results/2023.04.13_17.11.59/proto
04-13 17:12:00 D/LogFileSaver: Log data for tradefed-expanded-config is already compressed, skipping compression
04-13 17:12:00 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "tradefed-expanded-config_" suffix ".xml"
04-13 17:12:00 I/LogFileSaver: Saved log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/tradefed-expanded-config_13047561558003367028.xml. [size=33784, elapsed=0ms]
04-13 17:12:00 D/CertificationSuiteResultReporter: Saved logs for tradefed-expanded-config in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/tradefed-expanded-config_13047561558003367028.xml
04-13 17:12:00 D/LogFileSaver: Log data for tradefed-expanded-config is already compressed, skipping compression
04-13 17:12:00 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "tradefed-expanded-config_" suffix ".xml"
04-13 17:12:00 I/LogFileSaver: Saved log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/tradefed-expanded-config_3289501449920296295.xml. [size=33784, elapsed=0ms]
04-13 17:12:00 D/InvocationExecution: Starting device pre invocation setup for : '0001201904000455'
04-13 17:12:00 I/CommandInterrupter: Interrupt allowed
04-13 17:12:00 D/InvocationExecution: Starting setup for device: '0001201904000455'
04-13 17:12:00 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@7b963ded' on device: '0001201904000455'
04-13 17:12:00 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.treble.enabled] with timeout: 2m 0s
04-13 17:12:00 D/NativeDevice: Using 'ls' to check doesFileExist(/sys/fs/selinux/policy)
04-13 17:12:00 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:00 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:00 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@7b963ded' on device: '0001201904000455' in 323 ms
04-13 17:12:00 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@3af20b11' on device: '0001201904000455'
04-13 17:12:00 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.treble.enabled] with timeout: 2m 0s
04-13 17:12:00 D/NativeDevice: Using 'ls' to check doesFileExist(/proc/config.gz)
04-13 17:12:00 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:00 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:00 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@3af20b11' on device: '0001201904000455' in 297 ms
04-13 17:12:00 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.DynamicConfigPusher@13759048' on device: '0001201904000455'
04-13 17:12:00 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.DynamicConfigPusher@13759048' on device: '0001201904000455' in 187 ms
04-13 17:12:00 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.StayAwakePreparer@244d2aed' on device: '0001201904000455'
04-13 17:12:00 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.StayAwakePreparer@244d2aed' on device: '0001201904000455' in 108 ms
04-13 17:12:00 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.PackageDisabler@6efe12dc' on device: '0001201904000455'
04-13 17:12:01 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.PackageDisabler@6efe12dc' on device: '0001201904000455' in 104 ms
04-13 17:12:01 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@44fe3691' on device: '0001201904000455'
04-13 17:12:01 D/SettingsPreparer: Setting verifier_verify_adb_installs to value 0
04-13 17:12:01 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@44fe3691' on device: '0001201904000455' in 61 ms
04-13 17:12:01 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@7b360996' on device: '0001201904000455'
04-13 17:12:01 D/SettingsPreparer: Setting hide_error_dialogs to value 1
04-13 17:12:01 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@7b360996' on device: '0001201904000455' in 61 ms
04-13 17:12:01 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.ApkPreconditionCheck@36e14e5f' on device: '0001201904000455'
04-13 17:12:01 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:12:01 I/NativeDeviceStateMonitor: Waiting 359999 ms for device 0001201904000455 boot complete
04-13 17:12:01 I/DeviceStateMonitor: Waiting 359958 ms for device 0001201904000455 package manager
04-13 17:12:01 I/NativeDeviceStateMonitor: Waiting 359897 ms for device 0001201904000455 external store
04-13 17:12:01 I/ApkInstrumentationPreparer: Instrumenting package: com.android.preconditions.cts
04-13 17:12:01 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:01 D/CtsPreconditions.apk: Uploading CtsPreconditions.apk onto device '0001201904000455'
04-13 17:12:01 D/Device: Uploading file onto device '0001201904000455'
04-13 17:12:02 D/RunUtil: Running command [aapt, dump, badging, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsPreconditions.apk] with timeout: 1m 0s
04-13 17:12:02 D/RunUtil: Running command [aapt, dump, xmltree, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsPreconditions.apk, AndroidManifest.xml] with timeout: 1m 0s
04-13 17:12:02 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, appops, write-settings] with timeout: 2m 0s
04-13 17:12:02 D/ListInstrumentationParser: instrumentation:com.android.preconditions.cts/androidx.test.runner.AndroidJUnitRunner (target=com.android.preconditions.cts)
04-13 17:12:02 D/ListInstrumentationParser: 
04-13 17:12:02 I/InstrumentationTest: No runner name specified. Using: androidx.test.runner.AndroidJUnitRunner.
04-13 17:12:02 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:03 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:03 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:03 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:03 D/InstrumentationTest: Initializing com.android.tradefed.device.metric.CountTestCasesCollector for instrumentation.
04-13 17:12:03 I/RemoteAndroidTest: Running am instrument -w -r --no-isolated-storage   -e newRunListenerMode true -e timeout_msec 300000 com.android.preconditions.cts/androidx.test.runner.AndroidJUnitRunner on foxconn-bfx_at100-0001201904000455
04-13 17:12:05 D/BackgroundDeviceAction: Waiting for device 0001201904000455 online before starting.
04-13 17:12:05 D/BackgroundDeviceAction: Device 0001201904000455 now online.
04-13 17:12:05 D/BackgroundDeviceAction: Starting logcat for 0001201904000455.
04-13 17:12:05 D/TestDevice: Uninstalling com.android.preconditions.cts with extra args 
04-13 17:12:05 D/ApkInstrumentationPreparer: Target preparation successful
04-13 17:12:05 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.ApkPreconditionCheck@36e14e5f' on device: '0001201904000455' in 4s
04-13 17:12:05 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.WifiCheck@2817d2ad' on device: '0001201904000455'
04-13 17:12:06 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:12:06 I/NativeDeviceStateMonitor: Waiting 360000 ms for device 0001201904000455 boot complete
04-13 17:12:06 I/DeviceStateMonitor: Waiting 359893 ms for device 0001201904000455 package manager
04-13 17:12:06 I/NativeDeviceStateMonitor: Waiting 359776 ms for device 0001201904000455 external store
04-13 17:12:06 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:06 D/WifiUtil.apk16579585357724282961.apk: Uploading WifiUtil.apk16579585357724282961.apk onto device '0001201904000455'
04-13 17:12:06 D/Device: Uploading file onto device '0001201904000455'
04-13 17:12:07 D/RunUtil: Running command [aapt, dump, badging, /tmp/WifiUtil.apk16579585357724282961.apk] with timeout: 1m 0s
04-13 17:12:07 D/RunUtil: Running command [aapt, dump, xmltree, /tmp/WifiUtil.apk16579585357724282961.apk, AndroidManifest.xml] with timeout: 1m 0s
04-13 17:12:07 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, appops, write-settings] with timeout: 2m 0s
04-13 17:12:09 I/WifiCheck: Wifi is connected
04-13 17:12:09 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.WifiCheck@2817d2ad' on device: '0001201904000455' in 3s
04-13 17:12:09 D/InvocationExecution: starting preparer 'com.android.tradefed.targetprep.RunCommandTargetPreparer@1d683380' on device: '0001201904000455'
04-13 17:12:09 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, rm, -rf, /sdcard/device-info-files] with timeout: 2m 0s
04-13 17:12:09 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, rm, -rf, /sdcard/report-log-files] with timeout: 2m 0s
04-13 17:12:09 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, locksettings, set-disabled, true] with timeout: 2m 0s
04-13 17:12:10 D/InvocationExecution: done with preparer 'com.android.tradefed.targetprep.RunCommandTargetPreparer@1d683380' on device: '0001201904000455' in 1s
04-13 17:12:10 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.DeviceInfoCollector@5659e302' on device: '0001201904000455'
04-13 17:12:10 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.model] with timeout: 2m 0s
04-13 17:12:10 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.device] with timeout: 2m 0s
04-13 17:12:10 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.id] with timeout: 2m 0s
04-13 17:12:10 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.bootimage.build.fingerprint] with timeout: 2m 0s
04-13 17:12:10 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:10 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.manufacturer] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.serialno] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.security_patch] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.cpu.abilist32] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.reference.fingerprint] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.cpu.abi] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.cpu.abilist64] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.name] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.tags] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.incremental] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.brand] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.fingerprint] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.vendor.build.fingerprint] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.base_os] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.cpu.abilist] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.board] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.type] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.release] with timeout: 2m 0s
04-13 17:12:11 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.cpu.abi2] with timeout: 2m 0s
04-13 17:12:11 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:12:11 I/NativeDeviceStateMonitor: Waiting 360000 ms for device 0001201904000455 boot complete
04-13 17:12:11 I/DeviceStateMonitor: Waiting 359964 ms for device 0001201904000455 package manager
04-13 17:12:11 I/NativeDeviceStateMonitor: Waiting 359903 ms for device 0001201904000455 external store
04-13 17:12:12 I/ApkInstrumentationPreparer: Instrumenting package: com.android.compatibility.common.deviceinfo
04-13 17:12:12 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:12 D/CtsDeviceInfo.apk: Uploading CtsDeviceInfo.apk onto device '0001201904000455'
04-13 17:12:12 D/Device: Uploading file onto device '0001201904000455'
04-13 17:12:14 D/RunUtil: Running command [aapt, dump, badging, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsDeviceInfo.apk] with timeout: 1m 0s
04-13 17:12:14 D/RunUtil: Running command [aapt, dump, xmltree, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsDeviceInfo.apk, AndroidManifest.xml] with timeout: 1m 0s
04-13 17:12:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, appops, write-settings] with timeout: 2m 0s
04-13 17:12:14 D/ListInstrumentationParser: instrumentation:com.android.compatibility.common.deviceinfo/androidx.test.runner.AndroidJUnitRunner (target=com.android.compatibility.common.deviceinfo)
04-13 17:12:14 D/ListInstrumentationParser: instrumentation:com.android.tradefed.utils.wifi/.WifiUtil (target=com.android.tradefed.utils.wifi)
04-13 17:12:14 D/ListInstrumentationParser: 
04-13 17:12:14 I/InstrumentationTest: No runner name specified. Using: androidx.test.runner.AndroidJUnitRunner.
04-13 17:12:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:14 D/InstrumentationTest: Initializing com.android.tradefed.device.metric.CountTestCasesCollector for instrumentation.
04-13 17:12:14 I/RemoteAndroidTest: Running am instrument -w -r --no-isolated-storage   -e newRunListenerMode true -e timeout_msec 300000 com.android.compatibility.common.deviceinfo/androidx.test.runner.AndroidJUnitRunner on foxconn-bfx_at100-0001201904000455
04-13 17:12:29 D/TestDevice: Uninstalling com.android.compatibility.common.deviceinfo with extra args 
04-13 17:12:29 D/ApkInstrumentationPreparer: Target preparation successful
04-13 17:12:29 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:29 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:30 D/NativeDevice: Using 'ls' to check doesFileExist(/storage/emulated/0/device-info-files/)
04-13 17:12:30 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "framework_manifest.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/framework_manifest.xml_15848901320096249378.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/CertificationSuiteResultReporter: Saved logs for framework_manifest.xml in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/framework_manifest.xml_15848901320096249378.txt.gz
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "framework_manifest.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/framework_manifest.xml_9825711268515766233.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "GenericDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/GenericDeviceInfo.deviceinfo.json_5299168701771822291.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "device_manifest.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_manifest.xml_17353228912302449920.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/CertificationSuiteResultReporter: Saved logs for device_manifest.xml in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_manifest.xml_17353228912302449920.txt.gz
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "device_manifest.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/device_manifest.xml_11549524379283523477.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "MediaDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/MediaDeviceInfo.deviceinfo.json_17008509613781682996.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "StorageDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/StorageDeviceInfo.deviceinfo.json_12013156216299881432.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "SensorDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/SensorDeviceInfo.deviceinfo.json_15634751545637226861.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "AppStandbyDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/AppStandbyDeviceInfo.deviceinfo.json_16933926764828758873.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "device_compatibility_matrix.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_compatibility_matrix.xml_16757692310964186577.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/CertificationSuiteResultReporter: Saved logs for device_compatibility_matrix.xml in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_compatibility_matrix.xml_16757692310964186577.txt.gz
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "device_compatibility_matrix.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/device_compatibility_matrix.xml_16822550560057321643.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "PackageDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/PackageDeviceInfo.deviceinfo.json_2582872215132024940.txt.gz. [size=522, elapsed=2ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "framework_compatibility_matrix.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/framework_compatibility_matrix.xml_11500854830078802934.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/CertificationSuiteResultReporter: Saved logs for framework_compatibility_matrix.xml in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/framework_compatibility_matrix.xml_11500854830078802934.txt.gz
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "framework_compatibility_matrix.xml_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/framework_compatibility_matrix.xml_3468237609112389486.txt.gz. [size=10, elapsed=2ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "UserDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/UserDeviceInfo.deviceinfo.json_13985356552701468451.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "FeatureDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/FeatureDeviceInfo.deviceinfo.json_4143820110749567854.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "ConfigurationDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/ConfigurationDeviceInfo.deviceinfo.json_6180603270781905279.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "VintfDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/VintfDeviceInfo.deviceinfo.json_13537975736511765026.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "LocaleDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/LocaleDeviceInfo.deviceinfo.json_395230277186588912.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "CameraDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/CameraDeviceInfo.deviceinfo.json_2487972592301493564.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "CpuDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/CpuDeviceInfo.deviceinfo.json_18401275960388812231.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "VulkanDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/VulkanDeviceInfo.deviceinfo.json_16331036646243180974.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "ScreenDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/ScreenDeviceInfo.deviceinfo.json_15833692257540440308.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "GraphicsDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/GraphicsDeviceInfo.deviceinfo.json_3227687484704754278.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "ClientIdDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/ClientIdDeviceInfo.deviceinfo.json_5760499972146417625.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "MemoryDeviceInfo.deviceinfo.json_" suffix ".txt.gz"
04-13 17:12:30 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/MemoryDeviceInfo.deviceinfo.json_8393974394303607971.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:30 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.DeviceInfoCollector@5659e302' on device: '0001201904000455' in 20s
04-13 17:12:30 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.ReportLogCollector@6af6dc20' on device: '0001201904000455'
04-13 17:12:30 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.ReportLogCollector@6af6dc20' on device: '0001201904000455' in 0 ms
04-13 17:12:30 D/InvocationExecution: starting preparer 'com.android.tradefed.targetprep.RunCommandTargetPreparer@7c62f969' on device: '0001201904000455'
04-13 17:12:30 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, settings, put, global, package_verifier_enable, 0] with timeout: 2m 0s
04-13 17:12:31 D/InvocationExecution: done with preparer 'com.android.tradefed.targetprep.RunCommandTargetPreparer@7c62f969' on device: '0001201904000455' in 71 ms
04-13 17:12:31 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@204a2156' on device: '0001201904000455'
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.type] with timeout: 2m 0s
04-13 17:12:31 W/PropertyCheck: Expected "user" but found "userdebug" for property: ro.build.type
04-13 17:12:31 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@204a2156' on device: '0001201904000455' in 42 ms
04-13 17:12:31 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@391297ae' on device: '0001201904000455'
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.locale] with timeout: 2m 0s
04-13 17:12:31 W/PropertyCheck: Expected "en-US" but found "ko-KR" for property: ro.product.locale
04-13 17:12:31 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@391297ae' on device: '0001201904000455' in 41 ms
04-13 17:12:31 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@65595b70' on device: '0001201904000455'
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, persist.sys.test_harness] with timeout: 2m 0s
04-13 17:12:31 W/PropertyCheck: Property "persist.sys.test_harness" not found on device, cannot verify value "false" 
04-13 17:12:31 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@65595b70' on device: '0001201904000455' in 39 ms
04-13 17:12:31 D/InvocationExecution: starting preparer 'com.android.compatibility.common.tradefed.targetprep.BuildFingerPrintPreparer@a56df3e' on device: '0001201904000455'
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.fingerprint] with timeout: 2m 0s
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.vendor.build.fingerprint] with timeout: 2m 0s
04-13 17:12:31 D/InvocationExecution: done with preparer 'com.android.compatibility.common.tradefed.targetprep.BuildFingerPrintPreparer@a56df3e' on device: '0001201904000455' in 74 ms
04-13 17:12:31 D/InvocationExecution: Done with setup of device: '0001201904000455'
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, uname, -a] with timeout: 2m 0s
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.system.build.fingerprint] with timeout: 2m 0s
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.vendor.build.fingerprint] with timeout: 2m 0s
04-13 17:12:31 D/InvocationExecution: Total setup duration: 31s'
04-13 17:12:31 D/LogFileSaver: Log data for device_logcat_setup_0001201904000455 is already compressed, skipping compression
04-13 17:12:31 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "device_logcat_setup_0001201904000455_" suffix ".txt"
04-13 17:12:31 I/LogFileSaver: Saved log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_logcat_setup_0001201904000455_15870212735931718775.txt. [size=3313298, elapsed=5ms]
04-13 17:12:31 D/CertificationSuiteResultReporter: Saved logs for device_logcat_setup_0001201904000455 in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_logcat_setup_0001201904000455_15870212735931718775.txt
04-13 17:12:31 D/LogFileSaver: Log data for device_logcat_setup_0001201904000455 is already compressed, skipping compression
04-13 17:12:31 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "device_logcat_setup_0001201904000455_" suffix ".txt"
04-13 17:12:31 I/LogFileSaver: Saved log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/device_logcat_setup_0001201904000455_16365298493068804071.txt. [size=3313298, elapsed=4ms]
04-13 17:12:31 D/PrettyPrintDelimiter: 
===============================
===== TEST PHASE STARTING =====
===============================
04-13 17:12:31 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:12:31 I/NativeDeviceStateMonitor: Waiting 360000 ms for device 0001201904000455 boot complete
04-13 17:12:31 I/DeviceStateMonitor: Waiting 359965 ms for device 0001201904000455 package manager
04-13 17:12:31 I/NativeDeviceStateMonitor: Waiting 359903 ms for device 0001201904000455 external store
04-13 17:12:31 D/ResultsPlayer: Start replaying the previous results. Please wait this can take a few minutes.
04-13 17:12:31 D/ResultsPlayer: Done replaying results in 6 ms
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, cmd, device_state, print-states] with timeout: 2m 0s
04-13 17:12:31 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.product.cpu.abilist] with timeout: 2m 0s
04-13 17:12:31 D/ITestSuite: abi 'armeabi' is supported by device but not by this suite build ([arm64-v8a, armeabi-v7a]), tests will not run against it.
04-13 17:12:31 D/BaseTestSuite: Initializing ModuleRepo
ABIs:[{armeabi-v7a, bitness=32}]
Test Args:[com.android.tradefed.testtype.AndroidJUnitTest:exclude-annotation:com.android.compatibility.common.util.CtsDownstreamingTest, com.android.compatibility.common.tradefed.testtype.JarHostTest:exclude-annotation:com.android.compatibility.common.util.CtsDownstreamingTest, com.android.tradefed.testtype.HostTest:exclude-annotation:com.android.compatibility.common.util.CtsDownstreamingTest, com.android.tradefed.testtype.AndroidJUnitTest:exclude-annotation:android.platform.test.annotations.AsbSecurityTest, com.android.compatibility.common.tradefed.testtype.JarHostTest:exclude-annotation:android.platform.test.annotations.AsbSecurityTest, com.android.tradefed.testtype.AndroidJUnitTest:exclude-annotation:android.platform.test.annotations.AppModeInstant, com.android.compatibility.common.tradefed.testtype.JarHostTest:exclude-annotation:android.platform.test.annotations.AppModeInstant, com.android.tradefed.testtype.HostTest:exclude-annotation:android.platform.test.annotations.AppModeInstant]
Module Args:[]
Includes: {armeabi-v7a CtsGraphicsTestCases[instant]=[CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest], armeabi-v7a CtsGraphicsTestCases[run-on-work-profile]=[CtsGraphicsTestCases[run-on-work-profile] android.graphics.cts.SetFrameRateTest], armeabi-v7a CtsGraphicsTestCases[run-on-secondary-user]=[CtsGraphicsTestCases[run-on-secondary-user] android.graphics.cts.SetFrameRateTest], armeabi-v7a CtsGraphicsTestCases=[CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest]}
Excludes: {arm64-v8a CtsMediaBitstreamsTestCases=[arm64-v8a CtsMediaBitstreamsTestCases], armeabi-v7a CtsGraphicsTestCases[instant]=[armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testFixedSource_NonSeamless, armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_Seamless, armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testInvalidParams, armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testFixedSource_Seamless], armeabi-v7a CtsGraphicsTestCases=[armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_Seamless, armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testFixedSource_Seamless, armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testFixedSource_NonSeamless, armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testInvalidParams], x86_64 CtsMediaBitstreamsTestCases=[x86_64 CtsMediaBitstreamsTestCases], x86_64 CtsRenderscriptLegacyTestCases=[x86_64 CtsRenderscriptLegacyTestCases], x86_64 CtsLiblogTestCases=[x86_64 CtsLiblogTestCases liblog#event_log_tags], mips64 CtsMediaBitstreamsTestCases=[mips64 CtsMediaBitstreamsTestCases], mips64 CtsRenderscriptLegacyTestCases=[mips64 CtsRenderscriptLegacyTestCases], x86 CtsPerfettoTestCases=[x86 CtsPerfettoTestCases PerfettoTest#TestFtraceProducer], arm64-v8a CtsWrapWrapDebugMallocDebugTestCases=[arm64-v8a CtsWrapWrapDebugMallocDebugTestCases], arm64-v8a CtsRenderscriptLegacyTestCases=[arm64-v8a CtsRenderscriptLegacyTestCases]}
04-13 17:12:31 D/BaseTestSuite: Foldable states: [foldable:0:DEFAULT]
04-13 17:12:33 D/ITestSuite: Resource not found for allowed preparers: /suite/google-allowed-preparers.txt
04-13 17:12:33 D/ITestSuite: [Total Unique Modules = 2]
04-13 17:12:33 D/BaseTestSuite: Filters for 'armeabi-v7a CtsGraphicsTestCases[instant]': [armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testFixedSource_NonSeamless, armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_Seamless, armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testInvalidParams, armeabi-v7a CtsGraphicsTestCases[instant] android.graphics.cts.SetFrameRateTest#testFixedSource_Seamless]
04-13 17:12:33 I/ITestSuite: Running system status checker before module execution: armeabi-v7a CtsGraphicsTestCases[instant]
04-13 17:12:33 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:33 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:33 I/UserChecker: Current user 0 is already user type CURRENT, no action.
04-13 17:12:33 D/DeviceSettingChecker: Begin preExecutionCheck for checking device setting
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.type] with timeout: 2m 0s
04-13 17:12:34 I/DeviceBaselineChecker: Enable device baselines  in 0 millis.
04-13 17:12:34 D/ModuleDefinition: Running module armeabi-v7a CtsGraphicsTestCases[instant]
04-13 17:12:34 D/ModuleDefinition: Running setup preparer: SuiteApkInstaller
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.id] with timeout: 2m 0s
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.revision] with timeout: 2m 0s
04-13 17:12:34 D/NativeDevice: No valid MAC address queried from device 0001201904000455 by 'su root cat /sys/class/net/wlan0/address'
04-13 17:12:34 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.sim.state] with timeout: 2m 0s
04-13 17:12:35 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.operator.alpha] with timeout: 2m 0s
04-13 17:12:35 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:35 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.id] with timeout: 2m 0s
04-13 17:12:35 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.revision] with timeout: 2m 0s
04-13 17:12:35 D/NativeDevice: No valid MAC address queried from device 0001201904000455 by 'su root cat /sys/class/net/wlan0/address'
04-13 17:12:35 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.sim.state] with timeout: 2m 0s
04-13 17:12:35 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.operator.alpha] with timeout: 2m 0s
04-13 17:12:35 D/RunUtil: Running command [aapt, dump, badging, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk] with timeout: 1m 0s
04-13 17:12:35 D/RunUtil: Running command [aapt, dump, xmltree, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk, AndroidManifest.xml] with timeout: 1m 0s
04-13 17:12:35 D/TestAppInstallSetup: Installing apk android.graphics.cts with [/home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk] ...
04-13 17:12:35 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:35 D/CtsGraphicsTestCases.apk: Uploading CtsGraphicsTestCases.apk onto device '0001201904000455'
04-13 17:12:35 D/Device: Uploading file onto device '0001201904000455'
04-13 17:12:51 D/RunUtil: Running command [aapt, dump, badging, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk] with timeout: 1m 0s
04-13 17:12:51 D/RunUtil: Running command [aapt, dump, xmltree, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk, AndroidManifest.xml] with timeout: 1m 0s
04-13 17:12:51 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, appops, write-settings] with timeout: 2m 0s
04-13 17:12:51 D/AndroidJUnitTest: Attempting to push filters to /data/local/tmp/ajur/includes.txt
04-13 17:12:51 D/NativeDevice: Using 'ls' to check doesFileExist(/data/local/tmp/ajur)
04-13 17:12:51 D/NativeDevice: Using 'ls' to check doesFileExist(/data/local/tmp/ajur/includes.txt)
04-13 17:12:52 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D10637913816321957945.include_" suffix ".txt.gz"
04-13 17:12:52 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D10637913816321957945.include_17910124874098818450.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:52 D/CertificationSuiteResultReporter: Saved logs for filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D10637913816321957945.include in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D10637913816321957945.include_17910124874098818450.txt.gz
04-13 17:12:52 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D10637913816321957945.include_" suffix ".txt.gz"
04-13 17:12:52 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D10637913816321957945.include_14027955513064770950.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:52 D/AndroidJUnitTest: Attempting to push filters to /data/local/tmp/ajur/excludes.txt
04-13 17:12:52 D/NativeDevice: Using 'ls' to check doesFileExist(/data/local/tmp/ajur)
04-13 17:12:52 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D16892551123125477107.exclude_" suffix ".txt.gz"
04-13 17:12:52 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D16892551123125477107.exclude_10148982142392407432.txt.gz. [size=10, elapsed=1ms]
04-13 17:12:52 D/CertificationSuiteResultReporter: Saved logs for filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D16892551123125477107.exclude in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D16892551123125477107.exclude_10148982142392407432.txt.gz
04-13 17:12:52 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D16892551123125477107.exclude_" suffix ".txt.gz"
04-13 17:12:52 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/filter-armeabi-v7a%20CtsGraphicsTestCases%5Binstant%5D16892551123125477107.exclude_4715891658884749147.txt.gz. [size=10, elapsed=0ms]
04-13 17:12:52 D/ListInstrumentationParser: instrumentation:android.graphics.cts/androidx.test.runner.AndroidJUnitRunner (target=android.graphics.cts)
04-13 17:12:52 D/ListInstrumentationParser: instrumentation:com.android.tradefed.utils.wifi/.WifiUtil (target=com.android.tradefed.utils.wifi)
04-13 17:12:52 D/ListInstrumentationParser: 
04-13 17:12:52 I/InstrumentationTest: No runner name specified. Using: androidx.test.runner.AndroidJUnitRunner.
04-13 17:12:52 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:52 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:12:52 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:52 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:12:52 D/InstrumentationTest: Collecting test info for android.graphics.cts on device 0001201904000455
04-13 17:12:52 I/RemoteAndroidTest: Running am instrument -w -r --no-hidden-api-checks --abi armeabi-v7a  -e testFile /data/local/tmp/ajur/includes.txt -e debug false -e newRunListenerMode true -e log true -e notAnnotation android.platform.test.annotations.AsbSecurityTest,com.android.compatibility.common.util.CtsDownstreamingTest,android.platform.test.annotations.AppModeFull -e notTestFile /data/local/tmp/ajur/excludes.txt -e timeout_msec 300000 android.graphics.cts/androidx.test.runner.AndroidJUnitRunner on foxconn-bfx_at100-0001201904000455
04-13 17:12:54 D/InstrumentationTest: Initializing com.android.tradefed.device.metric.CountTestCasesCollector for instrumentation.
04-13 17:12:54 I/RemoteAndroidTest: Running am instrument -w -r --no-hidden-api-checks --abi armeabi-v7a  -e testFile /data/local/tmp/ajur/includes.txt -e debug false -e newRunListenerMode true -e log false -e notAnnotation android.platform.test.annotations.AsbSecurityTest,com.android.compatibility.common.util.CtsDownstreamingTest,android.platform.test.annotations.AppModeFull -e notTestFile /data/local/tmp/ajur/excludes.txt -e timeout_msec 300000 android.graphics.cts/androidx.test.runner.AndroidJUnitRunner on foxconn-bfx_at100-0001201904000455
04-13 17:12:55 D/ModuleListener: ModuleListener.testRunStarted(android.graphics.cts, 1, 0)
04-13 17:12:55 D/ModuleListener: ModuleListener.testStarted(android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless)
04-13 17:13:06 I/TestFailureListener: FailureListener.testFailed android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless false
04-13 17:13:06 I/ModuleListener: [1/1] android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless FAILURE: java.lang.AssertionError: Timed out waiting for a stable and compatible frame rate. expected=60.00 received=60.00. Stack trace: android.graphics.cts.FrameRateCtsActivity$FrameRateTimeoutException
	at android.graphics.cts.FrameRateCtsActivity.verifyCompatibleAndStableFrameRate(FrameRateCtsActivity.java:562)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$1$FrameRateCtsActivity(FrameRateCtsActivity.java:730)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda3.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runOneSurfaceTest(FrameRateCtsActivity.java:867)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:689)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$0$FrameRateCtsActivity(FrameRateCtsActivity.java:683)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda8.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:630)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)
	at java.lang.reflect.Method.invoke(Native Method)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:61)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:148)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:142)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:920)

	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:645)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)

04-13 17:13:08 D/ModuleListener: ModuleListener.testRunEnded(12703)
04-13 17:13:08 D/TestDevice: Uninstalling android.graphics.cts with extra args 
04-13 17:13:08 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:13:08 I/NativeDeviceStateMonitor: Waiting 360000 ms for device 0001201904000455 boot complete
04-13 17:13:09 I/DeviceStateMonitor: Waiting 359884 ms for device 0001201904000455 package manager
04-13 17:13:09 I/NativeDeviceStateMonitor: Waiting 359787 ms for device 0001201904000455 external store
04-13 17:13:09 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:09 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, persist.sys.boot.reason.history] with timeout: 2m 0s
04-13 17:13:09 W/NativeDevice: There is no reboot history since 1681377183000
04-13 17:13:09 E/ModuleDefinition: Detected a soft-restart after module armeabi-v7a CtsGraphicsTestCases[instant]
04-13 17:13:09 W/TestRunResult: armeabi-v7a CtsGraphicsTestCases[instant] calls testRunStarted more than once. Previous expected count: 4. New Expected count: 5
04-13 17:13:09 I/ConsoleReporter: [0001201904000455] Starting armeabi-v7a CtsGraphicsTestCases[instant] with 1 test
04-13 17:13:09 W/TestRunResult: armeabi-v7a CtsGraphicsTestCases[instant] calls testRunStarted more than once. Previous expected count: 4. New Expected count: 5
04-13 17:13:09 I/ConsoleReporter: [1/1 armeabi-v7a CtsGraphicsTestCases[instant] 0001201904000455] android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless fail: java.lang.AssertionError: Timed out waiting for a stable and compatible frame rate. expected=60.00 received=60.00. Stack trace: android.graphics.cts.FrameRateCtsActivity$FrameRateTimeoutException
	at android.graphics.cts.FrameRateCtsActivity.verifyCompatibleAndStableFrameRate(FrameRateCtsActivity.java:562)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$1$FrameRateCtsActivity(FrameRateCtsActivity.java:730)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda3.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runOneSurfaceTest(FrameRateCtsActivity.java:867)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:689)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$0$FrameRateCtsActivity(FrameRateCtsActivity.java:683)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda8.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:630)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)
	at java.lang.reflect.Method.invoke(Native Method)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:61)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:148)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:142)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:920)

	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:645)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)

04-13 17:13:09 I/ConsoleReporter: [0001201904000455] armeabi-v7a CtsGraphicsTestCases[instant] completed in 17s. 0 passed, 1 failed, 0 not executed
04-13 17:13:09 I/ITestSuite: Running system status checker after module execution: armeabi-v7a CtsGraphicsTestCases[instant]
04-13 17:13:09 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:13:09 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:10 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:13:10 I/NativeDeviceStateMonitor: Waiting 359999 ms for device 0001201904000455 boot complete
04-13 17:13:10 I/DeviceStateMonitor: Waiting 359958 ms for device 0001201904000455 package manager
04-13 17:13:10 I/NativeDeviceStateMonitor: Waiting 359897 ms for device 0001201904000455 external store
04-13 17:13:12 I/MonitoringUtils: Wifi Connectivity: passed check.
04-13 17:13:12 D/TestDevice: Output from KeyguardController:   KeyguardController:
    mKeyguardShowing=false
    mAodShowing=false
    mKeyguardGoingAway=false

04-13 17:13:12 E/LeakedThreadStatusChecker: We have 3 threads instead of 1. List: [Thread[Invocation-0001201904000455,5,Invocation-0001201904000455], Thread[BackgroundDeviceAction-logcat -v threadtime,uid,5,Invocation-0001201904000455], Thread[Timer-5,5,Invocation-0001201904000455]]
04-13 17:13:12 W/ITestSuite: System status checker [com.android.tradefed.suite.checker.LeakedThreadStatusChecker] failed
04-13 17:13:12 D/NativeDevice: Time offset = 1220 ms
04-13 17:13:12 D/DeviceSettingChecker: Begin postExecution for checking device setting
04-13 17:13:12 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:12 W/ITestSuite: There are failed system status checkers: {com.android.tradefed.suite.checker.LeakedThreadStatusChecker=We have 3 threads instead of 1. List: [Thread[Invocation-0001201904000455,5,Invocation-0001201904000455], Thread[BackgroundDeviceAction-logcat -v threadtime,uid,5,Invocation-0001201904000455], Thread[Timer-5,5,Invocation-0001201904000455]]}
04-13 17:13:12 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/results/2023.04.13_17.11.59/proto with prefix "tmp-proto" suffix ""
04-13 17:13:12 D/BaseTestSuite: Filters for 'armeabi-v7a CtsGraphicsTestCases': [armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_Seamless, armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testFixedSource_Seamless, armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testFixedSource_NonSeamless, armeabi-v7a CtsGraphicsTestCases android.graphics.cts.SetFrameRateTest#testInvalidParams]
04-13 17:13:12 I/ITestSuite: Running system status checker before module execution: armeabi-v7a CtsGraphicsTestCases
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:13 I/UserChecker: Current user 0 is already user type CURRENT, no action.
04-13 17:13:13 D/DeviceSettingChecker: Begin preExecutionCheck for checking device setting
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:13 I/DeviceBaselineChecker: Enable device baselines  in 0 millis.
04-13 17:13:13 D/ModuleDefinition: Running module armeabi-v7a CtsGraphicsTestCases
04-13 17:13:13 D/ModuleDefinition: Running setup preparer: SuiteApkInstaller
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:13:13 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.id] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.revision] with timeout: 2m 0s
04-13 17:13:14 D/NativeDevice: No valid MAC address queried from device 0001201904000455 by 'su root cat /sys/class/net/wlan0/address'
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.sim.state] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.operator.alpha] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.id] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.revision] with timeout: 2m 0s
04-13 17:13:14 D/NativeDevice: No valid MAC address queried from device 0001201904000455 by 'su root cat /sys/class/net/wlan0/address'
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.sim.state] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, gsm.operator.alpha] with timeout: 2m 0s
04-13 17:13:14 D/RunUtil: Running command [aapt, dump, badging, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk] with timeout: 1m 0s
04-13 17:13:14 D/RunUtil: Running command [aapt, dump, xmltree, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk, AndroidManifest.xml] with timeout: 1m 0s
04-13 17:13:14 D/TestAppInstallSetup: Installing apk android.graphics.cts with [/home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk] ...
04-13 17:13:14 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:14 D/CtsGraphicsTestCases.apk: Uploading CtsGraphicsTestCases.apk onto device '0001201904000455'
04-13 17:13:14 D/Device: Uploading file onto device '0001201904000455'
04-13 17:13:33 D/RunUtil: Running command [aapt, dump, badging, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk] with timeout: 1m 0s
04-13 17:13:33 D/RunUtil: Running command [aapt, dump, xmltree, /home/xts/tools/android-cts/tools/../../android-cts/testcases/CtsGraphicsTestCases.apk, AndroidManifest.xml] with timeout: 1m 0s
04-13 17:13:33 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, appops, write-settings] with timeout: 2m 0s
04-13 17:13:33 D/AndroidJUnitTest: Attempting to push filters to /data/local/tmp/ajur/includes.txt
04-13 17:13:33 D/NativeDevice: Using 'ls' to check doesFileExist(/data/local/tmp/ajur)
04-13 17:13:33 D/NativeDevice: Using 'ls' to check doesFileExist(/data/local/tmp/ajur/includes.txt)
04-13 17:13:33 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases10725597110308880086.include_" suffix ".txt.gz"
04-13 17:13:33 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases10725597110308880086.include_10710807718190533107.txt.gz. [size=10, elapsed=0ms]
04-13 17:13:33 D/CertificationSuiteResultReporter: Saved logs for filter-armeabi-v7a%20CtsGraphicsTestCases10725597110308880086.include in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases10725597110308880086.include_10710807718190533107.txt.gz
04-13 17:13:33 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases10725597110308880086.include_" suffix ".txt.gz"
04-13 17:13:33 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/filter-armeabi-v7a%20CtsGraphicsTestCases10725597110308880086.include_14387272427670750195.txt.gz. [size=10, elapsed=0ms]
04-13 17:13:33 D/AndroidJUnitTest: Attempting to push filters to /data/local/tmp/ajur/excludes.txt
04-13 17:13:33 D/NativeDevice: Using 'ls' to check doesFileExist(/data/local/tmp/ajur)
04-13 17:13:33 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases14107479782856176408.exclude_" suffix ".txt.gz"
04-13 17:13:33 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases14107479782856176408.exclude_1373491612639574037.txt.gz. [size=10, elapsed=1ms]
04-13 17:13:33 D/CertificationSuiteResultReporter: Saved logs for filter-armeabi-v7a%20CtsGraphicsTestCases14107479782856176408.exclude in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/filter-armeabi-v7a%20CtsGraphicsTestCases14107479782856176408.exclude_1373491612639574037.txt.gz
04-13 17:13:33 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "filter-armeabi-v7a%20CtsGraphicsTestCases14107479782856176408.exclude_" suffix ".txt.gz"
04-13 17:13:33 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/filter-armeabi-v7a%20CtsGraphicsTestCases14107479782856176408.exclude_7406335817588507757.txt.gz. [size=10, elapsed=0ms]
04-13 17:13:33 D/ListInstrumentationParser: instrumentation:android.graphics.cts/androidx.test.runner.AndroidJUnitRunner (target=android.graphics.cts)
04-13 17:13:33 D/ListInstrumentationParser: instrumentation:com.android.tradefed.utils.wifi/.WifiUtil (target=com.android.tradefed.utils.wifi)
04-13 17:13:33 D/ListInstrumentationParser: 
04-13 17:13:33 I/InstrumentationTest: No runner name specified. Using: androidx.test.runner.AndroidJUnitRunner.
04-13 17:13:33 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:33 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:13:33 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:33 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:33 D/InstrumentationTest: Collecting test info for android.graphics.cts on device 0001201904000455
04-13 17:13:33 I/RemoteAndroidTest: Running am instrument -w -r --no-hidden-api-checks --abi armeabi-v7a  -e testFile /data/local/tmp/ajur/includes.txt -e debug false -e newRunListenerMode true -e log true -e notAnnotation android.platform.test.annotations.AsbSecurityTest,android.platform.test.annotations.AppModeInstant,com.android.compatibility.common.util.CtsDownstreamingTest -e notTestFile /data/local/tmp/ajur/excludes.txt -e timeout_msec 300000 android.graphics.cts/androidx.test.runner.AndroidJUnitRunner on foxconn-bfx_at100-0001201904000455
04-13 17:13:35 D/InstrumentationTest: Initializing com.android.tradefed.device.metric.CountTestCasesCollector for instrumentation.
04-13 17:13:35 I/RemoteAndroidTest: Running am instrument -w -r --no-hidden-api-checks --abi armeabi-v7a  -e testFile /data/local/tmp/ajur/includes.txt -e debug false -e newRunListenerMode true -e log false -e notAnnotation android.platform.test.annotations.AsbSecurityTest,android.platform.test.annotations.AppModeInstant,com.android.compatibility.common.util.CtsDownstreamingTest -e notTestFile /data/local/tmp/ajur/excludes.txt -e timeout_msec 300000 android.graphics.cts/androidx.test.runner.AndroidJUnitRunner on foxconn-bfx_at100-0001201904000455
04-13 17:13:36 D/ModuleListener: ModuleListener.testRunStarted(android.graphics.cts, 1, 0)
04-13 17:13:36 D/ModuleListener: ModuleListener.testStarted(android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless)
04-13 17:13:47 I/TestFailureListener: FailureListener.testFailed android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless false
04-13 17:13:47 I/ModuleListener: [1/1] android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless FAILURE: java.lang.AssertionError: Timed out waiting for a stable and compatible frame rate. expected=60.00 received=60.00. Stack trace: android.graphics.cts.FrameRateCtsActivity$FrameRateTimeoutException
	at android.graphics.cts.FrameRateCtsActivity.verifyCompatibleAndStableFrameRate(FrameRateCtsActivity.java:562)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$1$FrameRateCtsActivity(FrameRateCtsActivity.java:730)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda3.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runOneSurfaceTest(FrameRateCtsActivity.java:867)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:689)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$0$FrameRateCtsActivity(FrameRateCtsActivity.java:683)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda8.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:630)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)
	at java.lang.reflect.Method.invoke(Native Method)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:61)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:148)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:142)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:920)

	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:645)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)

04-13 17:13:49 D/ModuleListener: ModuleListener.testRunEnded(12754)
04-13 17:13:49 D/TestDevice: Uninstalling android.graphics.cts with extra args 
04-13 17:13:49 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:13:49 I/NativeDeviceStateMonitor: Waiting 360000 ms for device 0001201904000455 boot complete
04-13 17:13:49 I/DeviceStateMonitor: Waiting 359934 ms for device 0001201904000455 package manager
04-13 17:13:50 I/NativeDeviceStateMonitor: Waiting 359702 ms for device 0001201904000455 external store
04-13 17:13:50 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:50 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, persist.sys.boot.reason.history] with timeout: 2m 0s
04-13 17:13:50 W/NativeDevice: There is no reboot history since 1681377224000
04-13 17:13:50 E/ModuleDefinition: Detected a soft-restart after module armeabi-v7a CtsGraphicsTestCases
04-13 17:13:50 W/TestRunResult: armeabi-v7a CtsGraphicsTestCases calls testRunStarted more than once. Previous expected count: 4. New Expected count: 5
04-13 17:13:50 I/ConsoleReporter: [0001201904000455] Starting armeabi-v7a CtsGraphicsTestCases with 1 test
04-13 17:13:50 W/TestRunResult: armeabi-v7a CtsGraphicsTestCases calls testRunStarted more than once. Previous expected count: 4. New Expected count: 5
04-13 17:13:50 I/ConsoleReporter: [1/1 armeabi-v7a CtsGraphicsTestCases 0001201904000455] android.graphics.cts.SetFrameRateTest#testExactFrameRateMatch_NonSeamless fail: java.lang.AssertionError: Timed out waiting for a stable and compatible frame rate. expected=60.00 received=60.00. Stack trace: android.graphics.cts.FrameRateCtsActivity$FrameRateTimeoutException
	at android.graphics.cts.FrameRateCtsActivity.verifyCompatibleAndStableFrameRate(FrameRateCtsActivity.java:562)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$1$FrameRateCtsActivity(FrameRateCtsActivity.java:730)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda3.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runOneSurfaceTest(FrameRateCtsActivity.java:867)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:689)
	at android.graphics.cts.FrameRateCtsActivity.lambda$testExactFrameRateMatch$0$FrameRateCtsActivity(FrameRateCtsActivity.java:683)
	at android.graphics.cts.FrameRateCtsActivity$$ExternalSyntheticLambda8.run(Unknown Source:4)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:630)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)
	at java.lang.reflect.Method.invoke(Native Method)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:61)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:148)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:142)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:920)

	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at android.graphics.cts.FrameRateCtsActivity.runTestsWithPreconditions(FrameRateCtsActivity.java:645)
	at android.graphics.cts.FrameRateCtsActivity.testExactFrameRateMatch(FrameRateCtsActivity.java:683)
	at android.graphics.cts.SetFrameRateTest.testExactFrameRateMatch_NonSeamless(SetFrameRateTest.java:94)

04-13 17:13:50 I/ConsoleReporter: [0001201904000455] armeabi-v7a CtsGraphicsTestCases completed in 17s. 0 passed, 1 failed, 0 not executed
04-13 17:13:50 I/ITestSuite: Running system status checker after module execution: armeabi-v7a CtsGraphicsTestCases
04-13 17:13:50 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:13:50 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:51 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:13:51 I/NativeDeviceStateMonitor: Waiting 360000 ms for device 0001201904000455 boot complete
04-13 17:13:51 I/DeviceStateMonitor: Waiting 359959 ms for device 0001201904000455 package manager
04-13 17:13:51 I/NativeDeviceStateMonitor: Waiting 359898 ms for device 0001201904000455 external store
04-13 17:13:53 I/MonitoringUtils: Wifi Connectivity: passed check.
04-13 17:13:53 D/TestDevice: Output from KeyguardController:   KeyguardController:
    mKeyguardShowing=false
    mAodShowing=false
    mKeyguardGoingAway=false

04-13 17:13:53 E/LeakedThreadStatusChecker: We have 3 threads instead of 1. List: [Thread[Invocation-0001201904000455,5,Invocation-0001201904000455], Thread[BackgroundDeviceAction-logcat -v threadtime,uid,5,Invocation-0001201904000455], Thread[Timer-5,5,Invocation-0001201904000455]]
04-13 17:13:53 W/ITestSuite: System status checker [com.android.tradefed.suite.checker.LeakedThreadStatusChecker] failed
04-13 17:13:53 D/NativeDevice: Time offset = 1226 ms
04-13 17:13:53 D/DeviceSettingChecker: Begin postExecution for checking device setting
04-13 17:13:53 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:53 W/ITestSuite: There are failed system status checkers: {com.android.tradefed.suite.checker.LeakedThreadStatusChecker=We have 3 threads instead of 1. List: [Thread[Invocation-0001201904000455,5,Invocation-0001201904000455], Thread[BackgroundDeviceAction-logcat -v threadtime,uid,5,Invocation-0001201904000455], Thread[Timer-5,5,Invocation-0001201904000455]]}
04-13 17:13:53 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/results/2023.04.13_17.11.59/proto with prefix "tmp-proto" suffix ""
04-13 17:13:53 D/PrettyPrintDelimiter: 
=============================
===== TEST PHASE ENDING =====
=============================
04-13 17:13:53 D/LogFileSaver: Log data for device_logcat_test_0001201904000455 is already compressed, skipping compression
04-13 17:13:53 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "device_logcat_test_0001201904000455_" suffix ".txt"
04-13 17:13:53 I/LogFileSaver: Saved log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_logcat_test_0001201904000455_5251806910179798748.txt. [size=1055208, elapsed=2ms]
04-13 17:13:53 D/CertificationSuiteResultReporter: Saved logs for device_logcat_test_0001201904000455 in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_logcat_test_0001201904000455_5251806910179798748.txt
04-13 17:13:53 D/LogFileSaver: Log data for device_logcat_test_0001201904000455 is already compressed, skipping compression
04-13 17:13:53 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "device_logcat_test_0001201904000455_" suffix ".txt"
04-13 17:13:53 I/LogFileSaver: Saved log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/device_logcat_test_0001201904000455_17516445535200626252.txt. [size=1055208, elapsed=3ms]
04-13 17:13:53 I/CommandInterrupter: Interrupt blocked
04-13 17:13:53 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "executeShellCommandLog_0001201904000455_" suffix ".txt.gz"
04-13 17:13:53 I/LogFileSaver: Saved gzip log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/executeShellCommandLog_0001201904000455_17454543978619217778.txt.gz. [size=10, elapsed=3ms]
04-13 17:13:53 D/CertificationSuiteResultReporter: Saved logs for executeShellCommandLog_0001201904000455 in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/executeShellCommandLog_0001201904000455_17454543978619217778.txt.gz
04-13 17:13:53 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "executeShellCommandLog_0001201904000455_" suffix ".txt.gz"
04-13 17:13:53 I/LogFileSaver: Saved gzip log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/executeShellCommandLog_0001201904000455_1695843809786598233.txt.gz. [size=10, elapsed=2ms]
04-13 17:13:53 D/TestInvocation: Checking that devices are online.
04-13 17:13:53 I/NativeDeviceStateMonitor: Device 0001201904000455 is already ONLINE
04-13 17:13:53 I/NativeDeviceStateMonitor: Waiting 360000 ms for device 0001201904000455 boot complete
04-13 17:13:54 I/DeviceStateMonitor: Waiting 359959 ms for device 0001201904000455 package manager
04-13 17:13:54 I/NativeDeviceStateMonitor: Waiting 359893 ms for device 0001201904000455 external store
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.BuildFingerPrintPreparer@a56df3e' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.BuildFingerPrintPreparer@a56df3e' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@65595b70' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@65595b70' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@391297ae' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@391297ae' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@204a2156' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.PropertyCheck@204a2156' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.tradefed.targetprep.RunCommandTargetPreparer@7c62f969' on device: '0001201904000455'
04-13 17:13:54 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, settings, put, global, package_verifier_enable, 1] with timeout: 2m 0s
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.tradefed.targetprep.RunCommandTargetPreparer@7c62f969' on device: '0001201904000455' in 72 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.ReportLogCollector@6af6dc20' on device: '0001201904000455'
04-13 17:13:54 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.codename] with timeout: 2m 0s
04-13 17:13:54 D/RunUtil: Running command [adb, -s, 0001201904000455, shell, getprop, ro.build.version.sdk] with timeout: 2m 0s
04-13 17:13:54 D/NativeDevice: Using 'ls' to check doesFileExist(/storage/emulated/0/report-log-files/)
04-13 17:13:54 E/NativeDevice: Device path /sdcard/report-log-files/ does not exist to be pulled.
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.ReportLogCollector@6af6dc20' on device: '0001201904000455' in 205 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.DeviceInfoCollector@5659e302' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.DeviceInfoCollector@5659e302' on device: '0001201904000455' in 1 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.tradefed.targetprep.RunCommandTargetPreparer@1d683380' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.tradefed.targetprep.RunCommandTargetPreparer@1d683380' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.WifiCheck@2817d2ad' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.WifiCheck@2817d2ad' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.ApkPreconditionCheck@36e14e5f' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.ApkPreconditionCheck@36e14e5f' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@7b360996' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@7b360996' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@44fe3691' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.SettingsPreparer@44fe3691' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.PackageDisabler@6efe12dc' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.PackageDisabler@6efe12dc' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.StayAwakePreparer@244d2aed' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.StayAwakePreparer@244d2aed' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.DynamicConfigPusher@13759048' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.DynamicConfigPusher@13759048' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@3af20b11' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@3af20b11' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/InvocationExecution: starting tearDown 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@7b963ded' on device: '0001201904000455'
04-13 17:13:54 D/InvocationExecution: done with tearDown 'com.android.compatibility.common.tradefed.targetprep.DeviceFileCollector@7b963ded' on device: '0001201904000455' in 0 ms
04-13 17:13:54 D/TestDevice: Uninstalling com.android.tradefed.utils.wifi with extra args 
04-13 17:13:55 D/WifiHelper: Successfully clean up WifiHelper.
04-13 17:13:55 D/RunUtil: Running command [id, -u, xts] with timeout: 1m 0s
04-13 17:13:55 D/RunUtil: Running command [tail, -c, 10MB, /tmp/adb.1000.log] with timeout: 1m 0s
04-13 17:13:55 D/LogFileSaver: Log data for host_adb_log is already compressed, skipping compression
04-13 17:13:55 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "host_adb_log_" suffix ".txt"
04-13 17:13:55 I/LogFileSaver: Saved log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/host_adb_log_10988401752062648438.txt. [size=902, elapsed=0ms]
04-13 17:13:55 D/CertificationSuiteResultReporter: Saved logs for host_adb_log in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/host_adb_log_10988401752062648438.txt
04-13 17:13:55 D/LogFileSaver: Log data for host_adb_log is already compressed, skipping compression
04-13 17:13:55 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "host_adb_log_" suffix ".txt"
04-13 17:13:55 I/LogFileSaver: Saved log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/host_adb_log_3309558466480107706.txt. [size=902, elapsed=0ms]
04-13 17:13:55 D/LogFileSaver: Log data for device_logcat_teardown_0001201904000455 is already compressed, skipping compression
04-13 17:13:55 D/FileUtil: Creating temp file at /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284 with prefix "device_logcat_teardown_0001201904000455_" suffix ".txt"
04-13 17:13:55 I/LogFileSaver: Saved log file /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_logcat_teardown_0001201904000455_18408056755350494028.txt. [size=5023, elapsed=0ms]
04-13 17:13:55 D/CertificationSuiteResultReporter: Saved logs for device_logcat_teardown_0001201904000455 in /home/xts/tools/android-cts/tools/../../android-cts/logs/2023.04.13_17.11.59/inv_6265483543940877284/device_logcat_teardown_0001201904000455_18408056755350494028.txt
04-13 17:13:55 D/LogFileSaver: Log data for device_logcat_teardown_0001201904000455 is already compressed, skipping compression
04-13 17:13:55 D/FileUtil: Creating temp file at /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470 with prefix "device_logcat_teardown_0001201904000455_" suffix ".txt"
04-13 17:13:55 I/LogFileSaver: Saved log file /tmp/9566628/cts/inv_13386742803945196181/inv_7481067889839748470/device_logcat_teardown_0001201904000455_9401631224021179416.txt. [size=5023, elapsed=1ms]
04-13 17:13:55 I/TestInvocation: Done stopping logcat for 0001201904000455
04-13 17:13:55 D/CommandScheduler: TestDeviceState for releasing '0001201904000455(class com.android.tradefed.device.TestDevice)' is 'ONLINE'
04-13 17:13:55 I/NativeDeviceStateMonitor: Waiting 30000 ms for device 0001201904000455 shell to be responsive
04-13 17:13:55 D/BackgroundDeviceAction: com.android.ddmlib.TimeoutException while running logcat on 0001201904000455. May see duplicated content in log.
04-13 17:13:55 D/BackgroundDeviceAction: Waiting for device 0001201904000455 online before starting.
04-13 17:13:55 D/CommandScheduler: Release map of the devices: {com.android.tradefed.device.TestDevice@34f809bc=AVAILABLE}
04-13 17:13:55 W/NativeDevice: Attempting to stop logcat when not capturing for 0001201904000455
