Roon Remote crashes on Android 11

Karl_Piplies · January 23, 2023, 6:48pm

Roon Core Machine

See Roon ARC 'Poor connection' when playing Tidal on cellular

Networking Gear & Setup Details

See Roon ARC 'Poor connection' when playing Tidal on cellular

Connected Audio Devices

Moto G6 Ali with LineageOS 18.1
Room Remote from APK 2.0 build 1192

Description of Issue

The app crashes periodically, i catched the logs from my phone:

01-23 19:41:33.589  1350  1365 I ActivityManager: Process com.roon.mobile (pid 4623) has died: fg  TOP
01-23 19:41:33.590     0     0 I [  689.072558,4] binder: undelivered transaction 363993, process died.
01-23 19:41:33.591  1350  1364 I WindowManager: WIN DEATH: Window{7946c66 u0 com.roon.mobile/com.roon.NativeActivityWithIntent}
01-23 19:41:33.591  1350  2698 E WifiMulticastLockManager: Multicaster binderDied
01-23 19:41:33.603  1786  1786 D StatusBar: disable<e i a s b h r c s > disable2<q i n >
01-23 19:41:33.604  1350  1365 E SparseMappingTable: can't store negative values key=0x6d10018 index=0 value=-26513 -- SparseMappingTable.Table{mSequence=1 mParent.mSequence=1 mParent.mLongs.size()=1 mSize=7 mTable=[0x0/0x0/0x6d8, 0x2/0x0/0x6d7, 0x4/0x0/0x6d9, 0x14/0x0/0x6d0, 0x16/0x0/0x6cf, 0x17/0x0/0x6bf, 0x18/0x0/0x6d1, 0x0/0x0/0x0, 0x0/0x0/0x0] clazz=com.android.internal.app.procstats.DurationsTable}
01-23 19:41:33.604  1350  1365 E SparseMappingTable: java.lang.RuntimeException: Stack trace
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable.logOrThrow(SparseMappingTable.java:645)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable.access$400(SparseMappingTable.java:46)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable$Table.setValue(SparseMappingTable.java:274)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable$Table.setValue(SparseMappingTable.java:259)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.DurationsTable.addDuration(DurationsTable.java:49)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.ServiceState.setForeground(ServiceState.java:380)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.bringDownServiceLocked(ActiveServices.java:3441)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.bringDownServiceIfNeededLocked(ActiveServices.java:3317)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.removeConnectionLocked(ActiveServices.java:3613)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.killServicesLocked(ActiveServices.java:3994)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService.cleanUpApplicationRecordLocked(ActivityManagerService.java:14769)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService.handleAppDiedLocked(ActivityManagerService.java:3764)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService.appDiedLocked(ActivityManagerService.java:3918)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied(ActivityManagerService.java:1609)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at android.os.IBinder$DeathRecipient.binderDied(IBinder.java:305)
01-23 19:41:33.604  1350  1365 E SparseMappingTable: 	at android.os.BinderProxy.sendDeathNotice(BinderProxy.java:664)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: can't store negative values key=0x6d00014 index=0 value=-26513 -- SparseMappingTable.Table{mSequence=1 mParent.mSequence=1 mParent.mLongs.size()=1 mSize=7 mTable=[0x0/0x0/0x6d8, 0x2/0x0/0x6d7, 0x4/0x0/0x6d9, 0x14/0x0/0x6d0, 0x16/0x0/0x6cf, 0x17/0x0/0x6bf, 0x18/0x0/0x6d1, 0x0/0x0/0x0, 0x0/0x0/0x0] clazz=com.android.internal.app.procstats.DurationsTable}
01-23 19:41:33.605  1350  1365 E SparseMappingTable: java.lang.RuntimeException: Stack trace
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable.logOrThrow(SparseMappingTable.java:645)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable.access$400(SparseMappingTable.java:46)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable$Table.setValue(SparseMappingTable.java:274)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.SparseMappingTable$Table.setValue(SparseMappingTable.java:259)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.DurationsTable.addDuration(DurationsTable.java:49)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.ServiceState.updateRunning(ServiceState.java:289)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.internal.app.procstats.ServiceState.setForeground(ServiceState.java:387)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.bringDownServiceLocked(ActiveServices.java:3441)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.bringDownServiceIfNeededLocked(ActiveServices.java:3317)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.removeConnectionLocked(ActiveServices.java:3613)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActiveServices.killServicesLocked(ActiveServices.java:3994)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService.cleanUpApplicationRecordLocked(ActivityManagerService.java:14769)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService.handleAppDiedLocked(ActivityManagerService.java:3764)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService.appDiedLocked(ActivityManagerService.java:3918)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied(ActivityManagerService.java:1609)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at android.os.IBinder$DeathRecipient.binderDied(IBinder.java:305)
01-23 19:41:33.605  1350  1365 E SparseMappingTable: 	at android.os.BinderProxy.sendDeathNotice(BinderProxy.java:664)
01-23 19:41:33.607  1350  1365 W ActivityTaskManager: Force removing ActivityRecord{4ff0ffb u0 com.roon.mobile/com.roon.NativeActivityWithIntent t186}: app died, no saved state
01-23 19:41:33.637  1350  1371 W ActivityManager: setHasOverlayUi called on unknown pid: 4623
01-23 19:41:33.655  1350  2732 W ActivityManager: Unable to start service Intent { act=com.android.launcher3.WINDOW_OVERLAY dat=app://com.android.launcher3:10138?v=9&cv=14 pkg=com.google.android.googlequicksearchbox } U=0: not found

I can restart the app and it runs normal 3-5 minutes, then it restarts again.

As the entrypoint for the stacktrace is a function called sendDeathNotice i suspect that log does not tell anything about the real reason the app has crashed, maybe you enabling verbose logging in the app helps?

Karl_Piplies · January 26, 2023, 12:02am

Okay, so in the meantime i switched to LineageOS 19.1 with android 12.
I looked at the logs more closely, i think this is an important part:

1-26 00:52:54.543  8269  8269 D Roon    : Surface has been created
01-26 00:52:54.543  8269  8269 D Roon    : Surface has changed: 1080 x 1944
01-26 00:52:54.543  8269  8309 D Roon    : Entering JNICreateSurface
01-26 00:52:54.551  1367  1573 I EventSequenceValidator: Transition from ACTIVITY_LAUNCHED to ACTIVITY_FINISHED
01-26 00:52:54.554   741   741 I android.hardware.power-service-qti: Power setMode: 5 to: 0
01-26 00:52:54.555     0     0 F         : [ 1525.566734,0] kgsl kgsl-3d0: |adreno_hang_int_callback| MISC: GPU hang detected
01-26 00:52:54.555     0     0 E         : [ 1525.566880,3] kgsl kgsl-3d0: com.roon.mobile[8269]: gpu fault ctx 37 ctx_type GL ts 161154 status E01801C5 rb 00c0/01ce ib1 00000007F78C8078/0868 ib2 00000007F787006C/0295
01-26 00:52:54.555     0     0 E         : [ 1525.566896,3] kgsl kgsl-3d0: com.roon.mobile[8269]: gpu fault rb 2 rb sw r/w 00c0/01ce
01-26 00:52:54.573     0     0 W [ 1525.566911,0] dropbox_queue_event: Dropping oldest event [gpu_ft_report]
01-26 00:52:54.573     0     0 F         : [ 1525.586942,0] kgsl kgsl-3d0: |adreno_hang_int_callback| MISC: GPU hang detected
01-26 00:52:54.573     0     0 E         : [ 1525.587289,7] kgsl kgsl-3d0: com.roon.mobile[8269]: gpu failed ctx 37 ts 161155
01-26 00:52:54.573  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0x400c0907 (IOCTL_KGSL_DEVICE_WAITTIMESTAMP_CTXTID) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.573  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.576  8269  8309 D RoonView: Created framebuffer using colorspace 0x00003089
01-26 00:52:54.576  8269  8309 D Roon    : 01/25 23:52:54 render area size changed value: 360x648
01-26 00:52:54.591  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.591  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.591  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.591  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.592  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.592  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.593  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.594  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.594  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.594  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.594  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.594  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.594  8269  8309 W Adreno-GSL: <gsl_ldd_control:549>: ioctl fd 84 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
01-26 00:52:54.594  8269  8309 W Adreno-GSL: <log_gpu_snapshot:458>: panel.gpuSnapshotPath is not set.not generating user snapshot
01-26 00:52:54.632  2303  2303 W Choreographer: Frame time is 0.060542 ms in the future!  Check that graphics HAL is generating vsync timestamps using the correct timebase.
01-26 00:52:54.651  1367  1485 W InputManager-JNI: Input channel object '3c8b027 SnapshotStartingWindow for taskId=37 (client)' was disposed without first being removed with the input manager!
01-26 00:52:54.680  1367  2342 E WifiMulticastLockManager: Multicaster binderDied
01-26 00:52:54.680  1367  7982 I WindowManager: WIN DEATH: Window{e2ad438 u0 com.roon.mobile/com.roon.NativeActivityWithIntent}
01-26 00:52:54.680  1367  2489 I ActivityManager: Process com.roon.mobile (pid 8269) has died: fg  TOP
01-26 00:52:54.681  1367  7982 W InputManager-JNI: Input channel object 'e2ad438 com.roon.mobile/com.roon.NativeActivityWithIntent (client)' was disposed without first being removed with the input manager!
01-26 00:52:54.681  1367  1589 I libprocessgroup: Successfully killed process cgroup uid 10106 pid 8269 in 0ms
01-26 00:52:54.682     0     0 W [ 1525.587348,5] dropbox_queue_event: Dropping oldest event [gpu_snapshot]
01-26 00:52:54.682     0     0 I [ 1525.694981,5] binder: undelivered transaction 765184, process died.
01-26 00:52:54.683   568   568 E BpTransactionCompletedListener: Failed to transact (-32)
01-26 00:52:54.686  1367  1573 V WindowManager: Unknown focus tokens, dropping reportFocusChanged
01-26 00:52:54.687  1367  2489 W ActivityManager: Scheduling restart of crashed service com.roon.mobile/com.roon.RAATServerService in 1000ms for start-requested

EDIT: I’ve tested Android 11 & 12, with the APK version and also with the Google Playstore, every time the app crashes it logs those deadlocks.

benjamin · January 26, 2023, 10:36pm

Hey @Karl_Piplies,

Thanks for your detailed info here! While we take a closer look at things, I wanted to confirm that you don’t experience any crashing while using Arc, correct?

If you could please take note of the date and time, the next time you experience a crash, that would be helpful. With that, could you please upload a fresh logset from the android device here after you’ve reproduced the crash?

I’ll be on standby for your reply

Karl_Piplies · January 28, 2023, 2:14pm

First of all thanks for your reply.

No this is all about Roon Remote on Android. I have submitted the important log part, timestamps are included i am at GMT+1.
The logs start at 28. Jan 15:08:58.076

benjamin · January 30, 2023, 11:13pm

Hey @Karl_Piplies,

We’ll need the full log set uploaded, if you could re-upload? Thanks

Karl_Piplies · January 31, 2023, 11:23pm

I’ve uploaded a log that starts at the start of Roon and ends after the crash. Inbetween i listened to music and left the smartphone locked.

benjamin · February 8, 2023, 12:10am

Hey @Karl_Piplies,

Sorry for any confusion! We’ll need the complete zipped-up logset, that would be helpful. Thanks!