Why can't HTC Droid running OTA 2.1 communicate with RFCOMM?
- by Brad Hein
Yesterday we received OTA Android 2.1 on my wife's HTC Droid - HOORAY!!! I am finally able to load my carputer app on her phone.
Well we loaded it, but it doesn't work. Specifically, it connects but sees no I/O!!!
I paired, re-paired, and re-paired again, every time its the same problem: connect() says we connected successfully, but any attempt to send or receive data appears to work but no data ever arrives in the input buffer.
The device I'm connecting to uses AT commands. ATI should respond with a device ID. That works fine when I run the app on my Moto Droid, but on the HTC droid, no data is ever present in the inputstream/buffer.
Personally, I'm feeling pretty sure it's a bug or limitation in this release for the HTC (because the app works great on my Moto A855 Droid).
Can anybody comment on the issue?
Obligatory code snippets:
Member variable defining my RFCOMM UUID
static final UUID UUID_RFCOMM_GENERIC = UUID.fromString("00001101-0000-1000-8000-00805F9B34FB");
Parts of my connect()
// make sure peer is defined as a valid device based on their MAC. If not then do it.
if (mBTDevice == null)
mBTDevice = mBTAdapter.getRemoteDevice(mPeerMAC);
// Make an RFCOMM binding.
try {mBTSocket = mBTDevice.createRfcommSocketToServiceRecord(UUID_RFCOMM_GENERIC);
} catch (Exception e1) {
msg ("connect(): Failed to bind to RFCOMM by UUID. msg=" + e1.getMessage());
return false;
}
msg ("connect(): Try to connect.");
try {
mBTSocket.connect();
} catch (Exception e) {
msg ("connect(): Exception thrown during connect: " + e.getMessage());
return false;
// there was a problem connecting... make a note of the particulars and move on.
}
msg ("connect(): CONNECTED!");
try {
mBTOutputStream = mBTSocket.getOutputStream();
mBTInputStream = new BufferedInputStream (mBTSocket.getInputStream(),INPUT_BUFFER_SIZE);
//msg ("Connecting non-buffered input stream...");
//mBTInputStream = mBTSocket.getInputStream();
} catch (Exception e) {
msg ("connect(): Error attaching i/o streams to socket. msg=" + e.getMessage());
return false;
}
resetErrorCounters();
setConnected(true);
return true;
}
Then I send "ATI\r"
and expect something like "CAN OBD II" but I get nothing.
mBTInputStream.available(), it seems, is ALWAYS zero, even when data should be in the input buffer.
There are GOBS of trace messages being generated by the OS as viewed with adb logcat -v time
Some of the more interesting ones:
05-17 19:44:21.447 D/BluetoothSppPort( 5809): connected to device service!
05-17 19:44:21.447 D/BluetoothSppPort( 5809): Creating a BluetoothSpp proxy object
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort called!
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort checking uuid
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort UUID=00001101-0000-1000-8000-00805f9b34fb auth=true encrypt=true
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort enforcing bluetooth perm
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort creating a jbtlspp object
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort checking if the btl spp object is valid
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort try to create an spp container
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort try to create security params
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort Set Security L2
05-17 19:44:21.467 D/BluetoothSppService( 74): createPort spp port create
05-17 19:44:21.467 D/JBtlSpp ( 74): create: Entered
05-17 19:44:21.467 D/JBtlSpp ( 74): Calling NativeJBtlSpp_Create
05-17 19:44:21.467 D/JBtlSppNative( 74): NativeJBtlSpp_Create: Entered
05-17 19:44:21.467 D/JBtlSppNative( 74): NativeJBtlSpp_Create: Calling BTL_SPP_Remote_Create
05-17 19:44:21.477 D/JBtlSppNative( 74): NativeJBtlSpp_Create: BTL_SPP_Remote_Create returned 0, context:18
05-17 19:44:21.477 D/JBtlSppNative( 74): NativeJBtlSpp_Create: Setting context value in jContext out parm
05-17 19:44:21.477 D/JBtlSppNative( 74): NativeJBtlSpp_Create: Calling Java setValue(0x18) in context's class
05-17 19:44:21.477 D/JBtlProfileContext( 74): setValue: setValue called, value:24
05-17 19:44:21.477 D/JBtlSppNative( 74): create_spp_port_data: will use context struct 0 for the port 24
05-17 19:44:21.477 D/JBtlSppNative( 74): create_spp_port_data: spp port context 0 added
05-17 19:44:21.477 D/JBtlSppNative( 74): NativeJBtlSpp_Create:Exiting Successfully
05-17 19:44:21.477 D/JBtlSpp ( 74): After NativeJBtlSpp_Create, status=SUCCESS, Context = 24
05-17 19:44:21.477 D/JBtlRbtlServices( 74): addUser: Entered, userRefCount = 1
05-17 19:44:21.477 D/BluetoothSppService( 74): port create returned status SUCCESS
05-17 19:44:21.477 D/JBtlSpp ( 74): enable: Entered
05-17 19:44:21.477 D/JBtlSpp ( 74): enable: UUID=00001101-0000-1000-8000-00805f9b34fb
05-17 19:44:21.477 D/JBtlSppNative( 74): NativeJBtlSpp_Enable: Entered
05-17 19:44:21.487 D/JBtlSppNative( 74): NativeJBtlSpp_Enable: BTL_SPP_Enable returned 0
05-17 19:44:21.487 D/JBtlSppNative( 74): NativeJBtlSpp_Enable:Exiting
05-17 19:44:21.487 D/JBtlSpp ( 74): After NativeJBtlSpp_Enable, status=SUCCESS
05-17 19:44:21.487 D/JBtlSpp ( 74): enable: Exiting
05-17 19:44:21.487 D/BluetoothSppService( 74): port enable returned status SUCCESS
05-17 19:44:21.487 D/BluetoothSppService( 74): connectPort called!
05-17 19:44:21.497 D/BluetoothSppService( 74): connectPort received bdaddress:00:18:E4:1D:23:9B
05-17 19:44:21.527 D/BluetoothSppService( 74): Trying to connect to 00:18:E4:1D:23:9B
05-17 19:44:21.527 D/JBtlSpp ( 74): setServiceName: Entered
05-17 19:44:21.527 D/JBtlSppNative( 74): NativeJBtlSpp_SetServiceName: Entered
05-17 19:44:21.547 D/JBtlSppNative( 74): NativeJBtlSpp_SetServiceName: native func returned 0
05-17 19:44:21.547 D/JBtlSppNative( 74): NativeJBtlSpp_SetServiceName:Exiting
05-17 19:44:21.547 D/JBtlSpp ( 74): After setServiceName, status=SUCCESS
05-17 19:44:21.547 D/JBtlSpp ( 74): setServiceName: Exiting
05-17 19:44:21.557 D/BluetoothSppService( 74): port setServiceName returned status SUCCESS
05-17 19:44:21.587 D/JBtlSpp ( 74): connect: Entered connecting to 00:18:E4:1D:23:9B
05-17 19:44:21.587 D/JBtlSppNative( 74): NativeJBtlSpp_Connect: Entered
05-17 19:44:21.597 D/JBtlSppNative( 74): NativeJBtlSpp_Connect: BTL_SPP_Connect returned 2
05-17 19:44:21.597 D/JBtlSppNative( 74): NativeJBtlSpp_Connect:Exiting
05-17 19:44:21.597 D/JBtlSpp ( 74): After NativeJBtlSpp_Connect, status=PENDING
05-17 19:44:21.747 D/AK8973 ( 61): Compass CLOSE
05-17 19:44:21.887 W/Process ( 74): Unable to open /proc/5749/status
05-17 19:44:21.917 I/ActivityManager( 74): Displayed activity com.gtosoft.dash/.Dash: 1279 ms (total 1279 ms)
05-17 19:44:24.047 D/ ( 74): signal_BTEVENT_ACCESSIBLE_CHANGE: Entered
05-17 19:44:24.047 D/ ( 74): signal_BTEVENT_ACCESSIBLE_CHANGE: Calling Java Accessible Change callback
05-17 19:44:24.047 D/JBtlBmg ( 74): nativeAccessibleChange
05-17 19:44:24.087 D/BluetoothService( 74): Callback - accessbileChange, btErrCode = NO_ERROR, mode = CONNECTABLE_ONLY
05-17 19:44:24.087 D/BluetoothService( 74): Sending ACTION_SCAN_MODE_CHANGED intent, mode = 21
05-17 19:44:24.087 D/ ( 74): signal_BTEVENT_ACCESSIBLE_CHANGE: Exiting
05-17 19:44:24.097 D/ ( 74): signal_BTEVENT_LINK_CONNECT_CNF: Entered
05-17 19:44:24.097 D/ ( 74): signal_BTEVENT_LINK_CONNECT_CNF: context: 1, errCode: 0
05-17 19:44:24.097 D/ ( 74): signal_BTEVENT_LINK_CONNECT_CNF: Calling Java Link Connect Confirmation callback
05-17 19:44:24.097 D/JBtlBmg ( 74): nativeLinkConnectCnf
05-17 19:44:24.107 D/BluetoothService( 74): Callback - linkConnectCnf, btErrCode = NO_ERROR, bdAddr = 00:18:E4:1D:23:9B
05-17 19:44:24.117 D/JBtlBmg ( 74): getKnownDeviceInfo: Entered
05-17 19:44:24.117 D/JBtlBmg ( 74): getKnownDeviceInfo: Calling NativeJBtlBmg_GetKnownDeviceInfo
05-17 19:44:24.137 D/ ( 74): NativeJBtlBmg_GetKnownDeviceInfo: Entered
05-17 19:44:24.137 D/ ( 74): NativeJBtlBmg_GetKnownDeviceInfo: Calling BTL_BMG_GetKnownDeviceInfo
05-17 19:44:24.227 D/JBtlBmgJniKnownDeviceInfo( 74): setValues: Entered
05-17 19:44:24.227 D/ ( 74): NativeJBtlBmg_GetKnownDeviceInfo:Exiting
05-17 19:44:24.227 D/JBtlBmg ( 74): getKnownDeviceInfo: After NativeJBtlBmg_GetKnownDeviceInfo, status=SUCCESS
05-17 19:44:24.227 D/JBtlBmg ( 74): getKnownDeviceInfo: Exiting
05-17 19:44:24.227 D/BluetoothService( 74): onRemoteDeviceConnected, device 00:18:E4:1D:23:9B is Paired
05-17 19:44:24.227 D/BluetoothService( 74): Sending ACTION_ACL_CONNECTED intent, address = 00:18:E4:1D:23:9B
05-17 19:44:24.227 D/BluetoothA2dpService( 74): Received intent with action: android.bluetooth.device.action.ACL_CONNECTED
05-17 19:44:24.227 D/ ( 74): signal_BTEVENT_LINK_CONNECT_CNF: Exiting
05-17 19:44:24.757 D/JBtlAg ( 163): setIndicatorValue: entered
05-17 19:44:24.767 I/JBtlAg ( 163): After NativeJBtlAg_SetIndicatorValue, status = SUCCESS
05-17 19:44:24.767 D/JBtlAg ( 163): setIndicatorValue: exiting
05-17 19:44:24.807 D/JBtlSppNative( 74): signal_SPP_EVENT_OPEN: Entered
05-17 19:44:24.807 D/JBtlSppNative( 74): signal_SPP_EVENT_OPEN: status: 0 context:24
05-17 19:44:24.827 D/JBtlSpp ( 74): nativeCb_open: Entered from 00:18:E4:1D:23:9B
05-17 19:44:24.827 D/JBtlSpp ( 74): nativeCb_open: Calling callback
05-17 19:44:24.827 D/BluetoothSppService( 74): connected called!
05-17 19:44:24.847 D/JBtlSpp ( 74): connect: Exiting
05-17 19:44:24.847 D/BluetoothSppService( 74): port connect returned status SUCCESS
05-17 19:44:24.847 D/JBtlSppNative( 74): signal_SPP_EVENT_OPEN: Exiting
05-17 19:44:24.847 D/JBtlSppNative( 74): signal_SPP_EVENT_MODEM_STATUS_IND: Entered
05-17 19:44:24.847 D/JBtlSppNative( 74): signal_SPP_EVENT_MODEM_STATUS_IND: Exiting
05-17 19:44:25.424 D/BluetoothSppService( 74): writeSync called!
05-17 19:44:25.424 D/JBtlSpp ( 74): write: Entered
05-17 19:44:25.427 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: Entered
05-17 19:44:25.427 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: BTL_SPP_WriteSync returned 0 written: 6 total: 0/6
05-17 19:44:25.437 D/JBtlSppNative( 74): signal_SPP_EVENT_TX_DATA_COMPLETE: Entered
05-17 19:44:25.437 D/JBtlSppNative( 74): signal_SPP_EVENT_TX_DATA_COMPLETE: status: 0 context:24 txDataLen:6
05-17 19:44:25.437 D/JBtlSppNative( 74): signal_SPP_EVENT_TX_DATA_COMPLETE: Exiting ok
05-17 19:44:25.437 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: written 6
05-17 19:44:25.437 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative:Exiting with 0
05-17 19:44:25.437 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: returning 6 bytes
05-17 19:44:25.437 D/JBtlSpp ( 74): After write, status=SUCCESS
05-17 19:44:25.437 D/JBtlSpp ( 74): write: Exiting
05-17 19:44:25.437 D/BluetoothSppPort( 5809): written 6 bytes
05-17 19:44:25.467 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Entered
05-17 19:44:25.467 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: status: 0 context: 24 rxDataLen: 1
05-17 19:44:25.467 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Exiting
05-17 19:44:25.477 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Entered
05-17 19:44:25.477 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: status: 0 context: 24 rxDataLen: 5
05-17 19:44:25.477 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Exiting
05-17 19:44:25.487 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Entered
05-17 19:44:25.487 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: status: 0 context: 24 rxDataLen: 10
05-17 19:44:25.487 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Exiting
05-17 19:44:25.497 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Entered
05-17 19:44:25.497 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: status: 0 context: 24 rxDataLen: 7
05-17 19:44:25.497 D/JBtlSppNative( 74): signal_SPP_EVENT_RX_DATA_IND: Exiting
05-17 19:44:27.930 W/ActivityManager( 74): Activity destroy timeout for HistoryRecord{447e0d48 com.gtosoft.dash/.Dash}
05-17 19:44:29.907 D/dalvikvm( 448): GC freed 78 objects / 3664 bytes in 153ms
05-17 19:44:29.917 D/BluetoothSppService( 74): writeSync called!
05-17 19:44:29.917 D/JBtlSpp ( 74): write: Entered
05-17 19:44:29.917 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: Entered
05-17 19:44:29.927 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: BTL_SPP_WriteSync returned 0 written: 6 total: 0/6
05-17 19:44:29.937 D/JBtlSppNative( 74): signal_SPP_EVENT_TX_DATA_COMPLETE: Entered
05-17 19:44:29.937 D/JBtlSppNative( 74): signal_SPP_EVENT_TX_DATA_COMPLETE: status: 0 context:24 txDataLen:6
05-17 19:44:29.937 D/JBtlSppNative( 74): signal_SPP_EVENT_TX_DATA_COMPLETE: Exiting ok
05-17 19:44:29.937 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: written 6
05-17 19:44:29.937 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative:Exiting with 0
05-17 19:44:29.937 D/JBtlSppNative( 74): NativeJBtlSpp_WriteNative: returning 6 bytes
05-17 19:44:29.937 D/JBtlSpp ( 74): After write, status=SUCCESS
05-17 19:44:29.937 D/JBtlSpp ( 74): write: Exiting
