BimmerGestalt / AAIdrive

Implementations of some Android Auto features as unofficial IDrive apps
MIT License
557 stars 92 forks source link

Audio Context has concurrency bug with the Etch connection #10

Closed hufman closed 5 years ago

hufman commented 5 years ago

There's also a deadlock:

Long monitor contention with owner Thread-51 (28509) at void me.hufman.androidautoidrive.carapp.RHMIApplicationSynchronized.setModel(int, java.lang.Object)(RHMIApplicationSynchronized.kt:13) waiters=1 in void me.hufman.androidautoidrive.carapp.RHMIApplicationSynchronized.setProperty(int, int, java.lang.Object) for 2.449s

hufman commented 5 years ago

07-25 19:04:18.678 25608 28509 W System.err: java.lang.RuntimeException: unexpected exception sending message
07-25 19:04:18.679 25608 28509 W System.err:    at org.apache.etch.bindings.java.transport.DefaultDeliveryService.begincall(DefaultDeliveryService.java:193)
07-25 19:04:18.679 25608 28509 W System.err:    at org.apache.etch.bindings.java.support.RemoteBase._begincall(RemoteBase.java:91)
07-25 19:04:18.679 25608 28509 W System.err:    at de.bmw.idrive.RemoteBMWRemotingServer$_Async._begin_rhmi_setData(RemoteBMWRemotingServer.java:2707)
07-25 19:04:18.679 25608 28509 W System.err:    at de.bmw.idrive.RemoteBMWRemotingServer.rhmi_setData(RemoteBMWRemotingServer.java:608)
07-25 19:04:18.679 25608 28509 W System.err:    at me.hufman.idriveconnectionkit.rhmi.RHMIApplicationEtch.setModel(RHMIApplication.kt:131)
07-25 19:04:18.679 25608 28509 W System.err:    at me.hufman.androidautoidrive.carapp.RHMIApplicationIdempotent.setModel(RHMIApplicationIdempotent.kt:14)
07-25 19:04:18.679 25608 28509 W System.err:    at me.hufman.androidautoidrive.carapp.RHMIApplicationSynchronized.setModel(RHMIApplicationSynchronized.kt:13)
07-25 19:04:18.679 25608 28509 W System.err:    at me.hufman.idriveconnectionkit.rhmi.RHMIModel$RaIntModel.setValue(RHMIModel.kt:74)
07-25 19:04:18.679 25608 28509 W System.err:    at me.hufman.androidautoidrive.carapp.RHMIModelMultiSetterInt.setValue(RHMIModelMultiSetter.kt:27)
07-25 19:04:18.679 25608 28509 W System.err:    at me.hufman.androidautoidrive.carapp.music.views.PlaybackView.redrawPosition(PlaybackView.kt:248)
07-25 19:04:18.679 25608 28509 W System.err:    at me.hufman.androidautoidrive.carapp.music.views.PlaybackView.redraw(PlaybackView.kt:180)
07-25 19:04:18.680 25608 28509 W System.err:    at me.hufman.androidautoidrive.carapp.music.views.PlaybackView.show(PlaybackView.kt:169)
07-25 19:04:18.680 25608 28509 W System.err:    at me.hufman.androidautoidrive.carapp.music.MusicApp$CarAppListener.rhmi_onHmiEvent(MusicApp.kt:121)
07-25 19:04:18.680 25608 28509 W System.err:    at de.bmw.idrive.StubBMWRemotingClient$4.run(StubBMWRemotingClient.java:120)
07-25 19:04:18.680 25608 28509 W System.err:    at de.bmw.idrive.StubBMWRemotingClient$4.run(StubBMWRemotingClient.java:115)
07-25 19:04:18.680 25608 28509 W System.err:    at org.apache.etch.bindings.java.support.StubBase$StubPoolRunnable.run(StubBase.java:202)
07-25 19:04:18.680 25608 28509 W System.err:    at org.apache.etch.bindings.java.support.QueuedPool$1.doit(QueuedPool.java:57)
07-25 19:04:18.680 25608 28509 W System.err:    at org.apache.etch.util.TodoManager.run(TodoManager.java:125)
07-25 19:04:18.680 25608 28509 W System.err:    at java.lang.Thread.run(Thread.java:764)
07-25 19:04:18.681 25608 28509 W System.err: Caused by: java.lang.IllegalStateException: connection down
07-25 19:04:18.681 25608 28509 W System.err:    at org.apache.etch.bindings.java.transport.PlainMailboxManager.register(PlainMailboxManager.java:178)
07-25 19:04:18.681 25608 28509 W System.err:    at org.apache.etch.bindings.java.transport.PlainMailboxManager.transportCall(PlainMailboxManager.java:144)
07-25 19:04:18.681 25608 28509 W System.err:    at org.apache.etch.bindings.java.transport.DefaultDeliveryService.begincall(DefaultDeliveryService.java:189)
07-25 19:04:18.681 25608 28509 W System.err:    ... 18 more
07-25 19:04:18.682 25608 28509 W System.err: java.io.IOException: closed
07-25 19:04:18.682 25608 28509 W System.err:    at org.apache.etch.util.core.io.TcpTransport.checkOutputStream(TcpTransport.java:224)
07-25 19:04:18.682 25608 28509 W System.err:    at org.apache.etch.util.core.io.TcpTransport.send(TcpTransport.java:177)
07-25 19:04:18.682 25608 28509 W System.err:    at org.apache.etch.util.core.io.TcpTransport.transportData(TcpTransport.java:262)
07-25 19:04:18.682 25608 28509 W System.err:    at org.apache.etch.util.core.io.Packetizer.transportPacket(Packetizer.java:259)
07-25 19:04:18.682 25608 28509 W System.err:    at org.apache.etch.bindings.java.transport.Messagizer.transportMessage(Messagizer.java:148)
07-25 19:04:18.683 25608 28509 W System.err:    at org.apache.etch.bindings.java.transport.PlainMailboxManager.transportMessage(PlainMailboxManager.java:129)
07-25 19:04:18.683 25608 28509 W System.err:    at org.apache.etch.bindings.java.transport.DefaultDeliveryService.transportMessage(DefaultDeliveryService.java:141)
07-25 19:04:18.683 25608 28509 W System.err:    at de.bmw.idrive.StubBMWRemotingClient$4.run(StubBMWRemotingClient.java:133)
07-25 19:04:18.683 25608 28509 W System.err:    at de.bmw.idrive.StubBMWRemotingClient$4.run(StubBMWRemotingClient.java:115)
07-25 19:04:18.683 25608 28509 W System.err:    at org.apache.etch.bindings.java.support.StubBase$StubPoolRunnable.run(StubBase.java:202)
07-25 19:04:18.683 25608 28509 W System.err:    at org.apache.etch.bindings.java.support.QueuedPool$1.doit(QueuedPool.java:57)
07-25 19:04:18.683 25608 28509 W System.err:    at org.apache.etch.util.TodoManager.run(TodoManager.java:125)
07-25 19:04:18.683 25608 28509 W System.err:    at java.lang.Thread.run(Thread.java:764)```
hufman commented 5 years ago

It seems to still be happening, reopening to look again

hufman commented 5 years ago

Ignoring this for now, it only seems to be reproduced with my Galaxy S9 on a USB connection, which can't even use the feature. I suspect there's some bad packet handling in the BCL module of the Connected app on these fast phones, which might not happen on slower Bluetooth connections on new cars that can actually use the Audio Context feature.