Marathon crash with `Unexpected string length`

[tabletenniser]

Describe the bug We are running Marathon in Jenkins CI for a while, recently, we started seeing crashes with the following stack trace:

00:04:00.685  Exception in thread "DeviceMonitor @coroutine#7" com.malinskiy.adam.exception.RequestRejectedException: Unexpected string length: 
00:04:00.685    at com.malinskiy.adam.extension.SocketKt.readProtocolString(Socket.kt:106)
00:04:00.685    at com.malinskiy.adam.extension.SocketKt$readProtocolString$1.invokeSuspend(Socket.kt)
00:04:00.685    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
00:04:00.685    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
00:04:00.685    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
00:04:00.685    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
00:04:00.685    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
00:04:00.685    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
00:04:00.685    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
00:04:00.685    at java.base/java.lang.Thread.run(Thread.java:840)
00:04:00.685    Suppressed: kotlinx.coroutines.DiagnosticCoroutineContextException: [CoroutineId(7), "coroutine#7":StandaloneCoroutine{Cancelling}@1ad16e30, java.util.concurrent.ScheduledThreadPoolExecutor@8ae1b27[Running, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 34]]

To Reproduce It roughly happens ~2% of the runs, couldn't find any consistent way to reproduce it

Expected behavior Tests pass without the failures

Logs and reports There's also warnings like the following in the log, not sure if it's relevant:

00:03:44.154  W 17:02:04.608 [AndroidDevice - execution - 127.0.0.1:5037:emulator-5554-1 @coroutine#13] <com.malinskiy.adam.request.Request> adb server rejected command 0016shell:getprop;echo x$?
00:03:44.154  Exception in thread "DeviceMonitor @coroutine#13" com.malinskiy.adam.exception.RequestRejectedException: closed
00:03:44.154    at com.malinskiy.adam.request.Request.handshake$suspendImpl(Request.kt:50)
00:03:44.154    at com.malinskiy.adam.request.Request$handshake$1.invokeSuspend(Request.kt)
00:03:44.154    at (Coroutine boundary.()
00:03:44.154    at com.malinskiy.marathon.android.adam.AdamDeviceProvider$initialize$5$2$1$job$1.invokeSuspend(AdamDeviceProvider.kt:157)
00:03:44.154    Suppressed: kotlinx.coroutines.DiagnosticCoroutineContextException: [CoroutineId(13), "coroutine#13":StandaloneCoroutine{Cancelling}@e8151c2, java.util.concurrent.ScheduledThreadPoolExecutor@8ae1b27[Running, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 23]]
00:03:44.154  Caused by: com.malinskiy.adam.exception.RequestRejectedException: closed
00:03:44.154    at com.malinskiy.adam.request.Request.handshake$suspendImpl(Request.kt:50)
00:03:44.154    at com.malinskiy.adam.request.Request$handshake$1.invokeSuspend(Request.kt)
00:03:44.154    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
00:03:44.154    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
00:03:44.154    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
00:03:44.154    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
00:03:44.154    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
00:03:44.154    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
00:03:44.154    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
00:03:44.154    at java.base/java.lang.Thread.run(Thread.java:840)

Devices (please complete the following information):

• Device: Android emulator running on AWS EC2 metal instance
• OS: Android

Any idea what might be causing this or any suggested potential work around will be very helpful!

[Malinskiy]

I've seen this when running large test runs. Unfortunately nothing much can be done from marathon's side. To limit the blast radius i suggest running mutiple adb servers.

My suspicion is something happened with adb server code or emulator adbd that introduced this problem

[Malinskiy]

Did you update any of the components recently? I know API 13/14 are more prone to this sort of behavior

[tabletenniser]

Thanks for the response! I guess we will grep the error string and if it contains Unexpected string length, we will do some retries on the caller side in that case then...

Did you update any of the components recently? I know API 13/14 are more prone to this sort of behavior We did not, we are actually running on google-30 which corresponds to API 11 if I read this correctly.

[Malinskiy]

One thing that can help you understand why this happens is to run tcpdump (probably with filters) and check which side is closing the socket here for adb connection