xharness: Install / Uninstall apk Sometimes Fails on Android

There are some runs indicated in https://github.com/dotnet/runtime/issues/44306 that show either the apk could not be installed or removed. Good examples of this are in:

https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-heads-master-0d80c385864846a9b0/JIT/console.17d80b24.log?sv=2019-07-07&se=2020-11-22T18%3A21%3A05Z&sr=c&sp=rl&sig=7poXAdaraL1BwYAj7GxDrIhZLK%2F9Uo6PZg8P022tEmM%3D

    [18:48:43] info: Attempting to remove apk 'net.dot.JIT_SIMD': 
      [18:48:43] fail: Error: Exit code: 224
                       Standard Output:
                       cmd: Failure calling service package: Broken pipe (32)

https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-43740-merge-1f95bf9c506d4bcb9e/JIT/console.8114e152.log?%3F%253F%25253Fsv%25253D2019-07-07%252526se%25253D2020-11-23T13%2525253A30%2525253A16Z%252526sr%25253Dc%252526sp%25253Drl%252526sig%25253Dyr2NQCCzTeXQKU3kTZHet06tu32Jnp1%2525252B6y3AUwdMIzM%2525253D

My guess is that adb is somehow corrupt and either resolves itself via workitem completion or an internal timeout. We should look into capturing the error state or states and try to correct it. We should try to avoid failing the tests the first time.

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 26 (26 by maintainers)

Commits related to this issue

Add a retry in the case of exit code 224; Seeks to address https://github.com/dotnet/xharness/issues/354 If this is insufficient there are some helix-based extra things to try. — committed to MattGal/xharness by MattGal 4 years ago
Add a retry in the case of exit code 224 (#361) * Add a retry in the case of exit code 224; Seeks to address https://github.com/dotnet/xharness/issues/354 If this is insufficient there are some he... — committed to dotnet/xharness by MattGal 4 years ago

Most upvoted comments

So looks like the https://github.com/dotnet/xharness/pull/388 is working for fixing the issue we saw during apk installation on some of the physical machines, I saw one machine got autofixed with the new xharness by rebooting the devices:

C:\h\w\A40208F8\w\AD510979\e>dotnet exec "C:\h\w\A40208F8\p/microsoft.dotnet.xharness.cli/1.0.0-prerelease.20601.1/tools/netcoreapp3.1/any/Microsoft.DotNet.XHarness.CLI.dll" android test --app "Microsoft.Extensions.FileProviders.Physical.Tests.apk" --output-directory "C:\h\w\A40208F8\w\AD510979\uploads" --timeout 1800 -p="net.dot.Microsoft.Extensions.FileProviders.Physical.Tests" -v -i=net.dot.MonoRunner  
XHarness command issued: android test --app Microsoft.Extensions.FileProviders.Physical.Tests.apk --output-directory C:\h\w\A40208F8\w\AD510979\uploads --timeout 1800 -p=net.dot.Microsoft.Extensions.FileProviders.Physical.Tests -v -i=net.dot.MonoRunner
[05:17:02] dbug: Android Test command called: App = C:\h\w\A40208F8\w\AD510979\e\Microsoft.Extensions.FileProviders.Physical.Tests.apk
                 Instrumentation Name = net.dot.MonoRunner
[05:17:02] dbug: Output Directory:C:\h\w\A40208F8\w\AD510979\uploads
                 Timeout = 1800 seconds.
[05:17:02] dbug: Arguments to instrumentation:
[05:17:02] dbug: ADBRunner using ADB.exe supplied from C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\tools\netcoreapp3.1\any\..\..\..\runtimes\any\native\adb\windows\adb.exe
[05:17:02] dbug: Full resolved path:'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe'
[05:17:02] info: Will attempt to run device on detected architecture: 'arm64-v8a'
[05:17:02] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe  start-server'
[05:17:02] dbug: 
[05:17:02] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe  devices -l'
[05:17:02] dbug: Evaluating output line for device serial: 017AY1S22P             device product:sargo model:Pixel_3a device:sargo transport_id:1
[05:17:02] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe  -s 017AY1S22P shell getprop ro.product.cpu.abi'
[05:17:03] info: Using first-found compatible device of 1 total- serial: '017AY1S22P' - Arch: arm64-v8a
[05:17:03] info: Active Android device set to serial '017AY1S22P'
[05:17:03] info: Waiting for device to be available (max 5 minutes)
[05:17:03] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P wait-for-device'
[05:17:03] dbug: 
[05:17:03] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P shell getprop sys.boot_completed'
[05:17:03] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P logcat -c'
[05:17:03] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P version'
[05:17:03] dbug: Working with Android Debug Bridge version 1.0.41
                 Version 29.0.6-6198805
                 Installed as C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe
                 
[05:17:03] info: Attempting to remove apk 'net.dot.Microsoft.Extensions.FileProviders.Physical.Tests': 
[05:17:03] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P uninstall net.dot.Microsoft.Extensions.FileProviders.Physical.Tests'
[05:17:03] info: APK 'net.dot.Microsoft.Extensions.FileProviders.Physical.Tests' not on device.
[05:17:03] info: Attempting to install C:\h\w\A40208F8\w\AD510979\e\Microsoft.Extensions.FileProviders.Physical.Tests.apk: 
[05:17:03] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P install "C:\h\w\A40208F8\w\AD510979\e\Microsoft.Extensions.FileProviders.Physical.Tests.apk"'
[05:17:06] warn: It seems the package installation cache may be full on the device.  We'll try to reboot it before trying one more time.
                 Output:Exit code: 1
                 Standard Output:
                 Performing Streamed Install
                 
                 Standard Error:
                 adb: failed to install C:\h\w\A40208F8\w\AD510979\e\Microsoft.Extensions.FileProviders.Physical.Tests.apk: Failure [INSTALL_FAILED_INSUFFICIENT_STORAGE: Scanning Failed.: Package net.dot.Microsoft.Extensions.FileProviders.Physical.Tests could not be assigned a valid UID]
                 
                 
[05:17:06] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P reboot'
[05:17:10] info: Waiting for device to be available (max 5 minutes)
[05:17:10] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P wait-for-device'
[05:17:19] dbug: 
[05:17:19] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P shell getprop sys.boot_completed'
[05:17:19] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P shell getprop sys.boot_completed'
[05:17:19] dbug: sys.boot_completed = ''
[05:17:29] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P shell getprop sys.boot_completed'
[05:17:29] dbug: sys.boot_completed = '1'
[05:17:39] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P install "C:\h\w\A40208F8\w\AD510979\e\Microsoft.Extensions.FileProviders.Physical.Tests.apk"'
[05:17:43] info: Successfully installed C:\h\w\A40208F8\w\AD510979\e\Microsoft.Extensions.FileProviders.Physical.Tests.apk.
[05:17:43] info: Killing all running processes for 'net.dot.Microsoft.Extensions.FileProviders.Physical.Tests': 
[05:17:43] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P shell am kill --user all net.dot.Microsoft.Extensions.FileProviders.Physical.Tests'
[05:17:43] dbug: Success!
                 
[05:17:43] info: Starting instrumentation class 'net.dot.MonoRunner' on net.dot.Microsoft.Extensions.FileProviders.Physical.Tests
[05:17:43] dbug: Raw command: 'shell am instrument  -w net.dot.Microsoft.Extensions.FileProviders.Physical.Tests/net.dot.MonoRunner'
[05:17:43] dbug: Executing command: 'C:\h\w\A40208F8\p\microsoft.dotnet.xharness.cli\1.0.0-prerelease.20601.1\runtimes\any\native\adb\windows\adb.exe -s 017AY1S22P shell am instrument  -w net.dot.Microsoft.Extensions.FileProviders.Physical.Tests/net.dot.MonoRunner'
[05:18:03] info: Running instrumentation class net.dot.MonoRunner took 20.1445738 seconds
[05:18:03] dbug: Exit code: 0
                 Standard Output:
                 INSTRUMENTATION_RESULT: return-code=0
                 INSTRUMENTATION_RESULT: test-results-path=/storage/emulated/0/Android/data/net.dot.Microsoft.Extensions.FileProviders.Physical.Tests/files/Documents/testResults.xml
                 INSTRUMENTATION_CODE: 0

@mattleibow that fix also includes your suggestion of using sys.boot_completed for ensuring the device is booted so please try xharness >= 1.0.0-prerelease.20601.1.

akoeplinger on Dec 2, 2020

Looks like XHarness 20601.1 which should contain the fix from https://github.com/dotnet/xharness/issues/354 is still failing: https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-45486-merge-3c2f97f16f154752a9/Microsoft.Extensions.Configuration.EnvironmentVariables.Tests/console.74bfb490.log?sv=2019-07-07&se=2020-12-23T10:26:30Z&sr=c&sp=rl&sig=ImcNQ%2BZX5lvEc%2FHKcQ1cjkfhiIu5go%2F%2F6dcPcPw2aWw%3D

[02:29:12] fail: Error:
                 Exit code: 1
                 Standard Output:
                 Performing Streamed Install
                 
                 Standard Error:
                 adb: failed to install C:\h\w\AB7309B6\w\BD3C0A3B\e\Microsoft.Extensions.Configuration.EnvironmentVariables.Tests.apk: cmd: Failure calling service package: Broken pipe (32)
                 
                 
[02:29:12] crit: Install failure: Test command cannot continue
XHarness exit code: 78

premun on Dec 3, 2020

“it has been failing on CI” refers to the default Azure hosted bots. I have to manually download, install, create and then spin them up.

mattleibow on Nov 27, 2020

Merged PR that does a single retry here, and moved the issue to validate. If this doesn’t make the problem go away I want to teach XHarness how to ask for reboot / retry when it detects it’s running in Helix.

MattGal on Nov 16, 2020