search

openxc / openxc-android

Android library for accessing vehicle data from an OpenXC vehicle interface
BSD 3-Clause "New" or "Revised" License
236 stars 115 forks source link

Issue connecting to Bluetooth with Enabler 5.1.0 and Android 2.3 #86

Closed nathorne closed 11 years ago

nathorne commented 11 years ago

Observations:

Bluetooth listed under Data Sources prior to being connected. VI connected over bluetooth. Notification appears in the trey - indicating the Service is connected to a VI. Bluetooth then disappears from Data Sources

The following stack trace was observed:

11-05 11:07:53.129: W/VehicleManager(2061): VehicleService disconnected unexpectedly
11-05 11:07:53.129: W/RemoteListenerSource(2061): Unable to register to receive measurement callbacks
11-05 11:07:53.129: W/RemoteListenerSource(2061): android.os.DeadObjectException
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at android.os.BinderProxy.transact(Native Method)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at com.openxc.remote.VehicleServiceInterface$Stub$Proxy.unregister(VehicleServiceInterface.java:275)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at com.openxc.sources.RemoteListenerSource.stop(RemoteListenerSource.java:43)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at com.openxc.DataPipeline.removeSource(DataPipeline.java:143)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at com.openxc.VehicleManager$1.onServiceDisconnected(VehicleManager.java:599)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at android.app.LoadedApk$ServiceDispatcher.doDeath(LoadedApk.java:1069)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1083)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at android.os.Handler.handleCallback(Handler.java:587)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at android.os.Handler.dispatchMessage(Handler.java:92)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at android.os.Looper.loop(Looper.java:130)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at android.app.ActivityThread.main(ActivityThread.java:3835)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at java.lang.reflect.Method.invokeNative(Native Method)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at java.lang.reflect.Method.invoke(Method.java:507)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:864)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:622)
11-05 11:07:53.129: W/RemoteListenerSource(2061):   at dalvik.system.NativeStart.main(Native Method)
nathorne commented 11 years ago

Note that the stack trace above was listed as a "warning" not an "error".

peplin commented 11 years ago

Was there anything before the stack trace to say why the VehicleService may have died?

nathorne commented 11 years ago

Yes... I just duplicated the issue. Just before the exception listed above is a thread exiting with an uncaught exception. See the full log (from a fresh start of the app):

11-05 13:24:12.899: I/BluetoothVehicleInterface(14722): Socket stream to vehicle interface opened successfully
11-05 13:24:12.899: D/VehicleService(14722): Wake lock acquired
11-05 13:24:12.899: I/VehicleService(14722): Moving service to foreground.
11-05 13:24:12.919: W/dalvikvm(14722): threadid=11: thread exiting with uncaught exception (group=0x40015560)
11-05 13:24:12.919: W/dalvikvm(14722): threadid=12: thread exiting with uncaught exception (group=0x40015560)
11-05 13:24:12.919: I/Process(14722): Sending signal. PID: 14722 SIG: 9
11-05 13:24:12.979: W/VehicleManager(14695): VehicleService disconnected unexpectedly
11-05 13:24:12.979: W/RemoteListenerSource(14695): Unable to register to receive measurement callbacks
11-05 13:24:12.979: W/RemoteListenerSource(14695): android.os.DeadObjectException
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at android.os.BinderProxy.transact(Native Method)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at com.openxc.remote.VehicleServiceInterface$Stub$Proxy.unregister(VehicleServiceInterface.java:275)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at com.openxc.sources.RemoteListenerSource.stop(RemoteListenerSource.java:43)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at com.openxc.DataPipeline.removeSource(DataPipeline.java:143)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at com.openxc.VehicleManager$1.onServiceDisconnected(VehicleManager.java:599)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at android.app.LoadedApk$ServiceDispatcher.doDeath(LoadedApk.java:1069)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1083)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at android.os.Handler.handleCallback(Handler.java:587)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at android.os.Handler.dispatchMessage(Handler.java:92)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at android.os.Looper.loop(Looper.java:130)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at android.app.ActivityThread.main(ActivityThread.java:3835)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at java.lang.reflect.Method.invokeNative(Native Method)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at java.lang.reflect.Method.invoke(Method.java:507)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:864)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:622)
11-05 13:24:12.979: W/RemoteListenerSource(14695):  at dalvik.system.NativeStart.main(Native Method)
11-05 13:24:12.979: I/VehicleManager(14695): Binding to VehicleService
11-05 13:24:13.029: D/szipinf(14763): Initializing inflate state
11-05 13:24:13.049: I/VehicleService(14763): Service starting
11-05 13:24:13.049: I/VehicleService(14763): Service binding in response to Intent { act=com.openxc.remote.VehicleServiceInterface }
11-05 13:24:13.059: I/VehicleManager(14695): Bound to VehicleService
11-05 13:24:13.059: I/VehicleService(14763): Adding listener com.openxc.remote.VehicleServiceListener$Stub$Proxy@40521c18
11-05 13:24:23.729: D/dalvikvm(14695): GC_CONCURRENT freed 290K, 51% free 2819K/5639K, external 545K/587K, paused 6ms+2ms
nathorne commented 11 years ago

@peplin, it appears the issue is caused by the following code (line 78) in BluetoothVehicleInterface.java:

@Override
public boolean isConnected() {
        mConnectionLock.readLock().lock();
        boolean connected = mSocket != null && mSocket.isConnected() &&
            super.isConnected();
        mConnectionLock.readLock().unlock();
        return connected;
}

The method BluetoothSocket.isConnected() does not exist until API 14 so it throws an uncaught NoSuchMethodError exception. I'm working on a way to do this which is more backwards compatible.

peplin commented 11 years ago

Nice catch - I wonder why I wasn't getting the usual target API warning when using that function.

Worst case, since I think checking if mSocket == null is going to be the most reliable indicator of a connection, we can try and call isConnected and catch the NoSuchMethod exception if it's thrown.

nathorne commented 11 years ago

Thanks!

Agreed, I think that's probably the best bet.

nathorne commented 11 years ago

Fixed in #87