My application connects to Bluetooth SPP modules by making and handling connections pretty much as described in the Android Bluetooth documentation. That is, in my connection thread, I have been used to making a connection simply using:
socket = device.createRfcommSocketToServiceRecord(MY_UUID)
where the UUID is the ‘well known’ SPP UUID, 00001101-0000-1000-8000-00805F9B34FB.
The Bluetooth devices I am connecting to are little Bluetooth / serial adapters. I have three that I’ve been using for test. Two of them are the “Linvor” Bluetooth to TTL-level serial PCBs that are all over eBay at the moment, which are identical; and the third is a completely enclosed adapter of manufacturer unknown.
Over the time I have been developing this application, I have routinely tested on various devices that range from Android version 2.2.1 (my old Archos 101) through to an Archos Honeycomb device. The device I have been testing on mostly is my Desire HD, which presently has Android version 2.3.5. Over the year or so I have been working on this, I can confidently say that I’ve never had any connection problems.
Yesterday during testing with my Desire HD (2.3.5) I found that the application would no longer connect to my Linvor Bluetooth PCB I have been working with mostly lately. After obtaining the socket using the line of code quoted above, when attempting socket.connect()
, I would immediately get an IOException
of Unable to start discovery
.
The next thing I did was to swap over to my other spare Linvor module and attempt to pair and connect. The application connected just fine. I also then swapped in my third packaged Bluetooth adapter, and the application connected to that just fine, too. Going back to my first Linvor module, the application still refuses to connect. I ensure that I unpair the ‘faulty’ Linvor device on my Desire HD, turn off Bluetooth, power down the phone, remove and re-insert battery, power-up, re-pair etc. and then try once again. The application still refuses to connect to that first Linvor module, but connects fine to the second Linvor module and other adapter module.
I then grab my Archos 101 (2.2.1) and fire up a somewhat older build of my application that is still installed on it. The Archos 101 immediately connects to the ‘faulty’ Linvor module just fine.
At this point I am starting to wonder if either device – i.e. my Desire HD, or perhaps more likely the Linvor module – could have some corrupt entry in its flash memory table for paired devices. In other words, something within that first Linvor module that means it no longer accepts a connection (although it does accept a pairing) from my Desire HD, and yet it will still accept connections from other devices; and also at the same time my Desire HD can happily connect to other devices just as it always has done, including the other spare Linvor module.
After hours of head-scratching and desperation, I decided to try out the reflection connection method as described in Michael’s answer here. This is something I have heard about quite a lot and I was under the impression that it’s applicable to Android 2.2 and below. However, for the entire year that I have been working with Bluetooth SPP from my various Android devices, I have never needed to use it as .createRfcommSocketToServiceRecord()
has always worked for me. So I use the code as given in Michael’s answer to that question to create my socket
, and to my amazement, my Desire HD connects to the ‘faulty’ Linvor module.
So to recap, the situation seems to be like this:
For the past year, I have been able to use .createRfcommSocketToServiceRecord()
routinely on my 2.2.1 and 2.3.5 devices to connect to my three Bluetooth SPP adapters.
Then, one particular day, without any change to software on phones or on my Bluetooth adapters, the first of the adapters suddenly requires the reflection method for a connection to work; the other two adapters (one of which is the same type as the first) continue to connect with my application just fine using .createRfcommSocketToServiceRecord()
. Note that there had been absolutely no changes made to my Bluetooth code immediately prior to this sudden changes in behaviour.
What on earth is going on here?
Can anyone advise me on what Android version level the reflection ‘hack’ should not be required? I was under the impression that it should not longer be necessary on, say, 2.3.5 (my Desire HD). Is that correct?
Is / was the nature of the bug with .createRfcommSocketToServiceRecord()
such that connections would usually work, but sometimes not work depending on the phase of the moon?
Here is a Logcat output from when a connection fails with that particular Linvor module when using .createRfcommSocketToServiceRecord()
:
01-29 10:22:00.004: D/View(8165): onTouchEvent: viewFlags: 0x18005001
01-29 10:22:00.014: D/View(8165): onTouchEvent: isFocusable: true, isFocusableInTouchMode: false, isFocused: false; focusTaken: false
01-29 10:22:00.034: D/WindowManagerImpl(8165): finishRemoveViewLocked, mViews2: com.android.internal.policy.impl.PhoneWindow$DecorView@406215d8
01-29 10:22:00.074: I/BLZ20_WRAPPER(8165): blz20_wrp_socket: fam 31, type 1, prot BTPROTO_RFCOMM
01-29 10:22:00.084: D/BLZ20_WRAPPER(8165): blz20_init: initializing...
01-29 10:22:00.084: D/BTL_IFC_WRP(8165): wsactive_init: init active list
01-29 10:22:00.084: I/BTL_IFC(8165): main_client_thread: Client main thread starting
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): blz20_init: success
01-29 10:22:00.194: I/BTL_IFC(8165): BTL_IFC_RegisterSubSystem: Register subsystem [BTS]
01-29 10:22:00.194: I/BTL_IFC(8165): btl_ifc_ctrl_connect: Connect control channel for subsystem [BTS]
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_sock_create: CTRL
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_alloc_new_sock: wrp_alloc_new_sock sub 1
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_sock_create: 66
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_sock_connect: wrp_sock_connect brcm.bt.btlif:9000 (66)
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_sock_connect: BTLIF_MAKE_LOCAL_SERVER_NAME return name: brcm.bt.btlif.9000
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_sock_connect: wrp_sock_connect ret:0 server name:brcm.bt.btlif.9000
01-29 10:22:00.194: I/BTL_IFC_WRP(8165): wrp_sock_connect: Connected. (66)
01-29 10:22:00.194: I/BTL_IFC(8165): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_REGISTER_SUBSYS_REQ (BTS) 0 pbytes (hdl 66)
01-29 10:22:00.194: D/BTL_IFC(8165): BTL_IFC_RegisterSubSystem: add new ctrl fd to active set
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_wsock_create: BTS
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_alloc_new_sock: wrp_alloc_new_sock sub 16
01-29 10:22:00.194: D/BTL_IFC_WRP(8165): wrp_wsock_create: 67
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): btsk_alloc_add: success
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): btsk_dump_list: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_socket: return 67
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): blz20_wrp_setsockopt: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_setsockopt: configure rfcomm lm mode 0x26, (master:0, auth 1, enc 1)
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_setsockopt: success
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): blz20_wrp_setsockopt: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_setsockopt: configure rfcomm sndbuf len 71680 bytes
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_setsockopt: success
01-29 10:22:00.194: D/BLZ20_ASOCKWRP(8165): asocket_init
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: s 67, cmd 3
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: s 67, cmd 4
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.194: D/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: transparant fcntl
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: s 69, cmd 3
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: wsock not found, pass through transparantly
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: s 69, cmd 4
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_wrp_fcntl: wsock not found, pass through transparantly
01-29 10:22:00.194: I/BLZ20_WRAPPER(8165): blz20_set_asocket: success (67,68,69)
01-29 10:22:00.214: I/BluetoothIF(8165): BEGIN mConnectThread
01-29 10:22:00.234: E/BluetoothIF(8165): TP: IOException error: java.io.IOException: Unable to start Service Discovery
01-29 10:22:00.234: E/BluetoothIF(8165): Unable to start Service Discovery
01-29 10:22:00.234: E/BluetoothIF(8165): Unable to start Service Discovery
01-29 10:22:00.234: D/BluetoothSocket(8165): close(): android.bluetooth.BluetoothSocket@405c8f78
01-29 10:22:00.234: D/BLZ20_ASOCKWRP(8165): asocket_abort [67,68,69]
01-29 10:22:00.234: I/BLZ20_WRAPPER(8165): blz20_wrp_shutdown: s 67, how 2
01-29 10:22:00.234: D/BLZ20_WRAPPER(8165): blz20_wrp_shutdown: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.234: I/BLZ20_WRAPPER(8165): blz20_wrp_shutdown: shutdown socket
01-29 10:22:00.234: D/BLZ20_WRAPPER(8165): blz20_wrp_write: wrote 1 bytes out of 1 on fd 69
01-29 10:22:00.234: D/BLZ20_ASOCKWRP(8165): asocket_destroy
01-29 10:22:00.234: D/BLZ20_ASOCKWRP(8165): asocket_abort [67,68,69]
01-29 10:22:00.234: I/BLZ20_WRAPPER(8165): blz20_wrp_shutdown: s 67, how 2
01-29 10:22:00.234: D/BLZ20_WRAPPER(8165): blz20_wrp_shutdown: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.234: I/BLZ20_WRAPPER(8165): blz20_wrp_shutdown: shutdown socket
01-29 10:22:00.234: D/BLZ20_WRAPPER(8165): blz20_wrp_write: wrote 1 bytes out of 1 on fd 69
01-29 10:22:00.234: I/BLZ20_WRAPPER(8165): blz20_wrp_close: s 69
01-29 10:22:00.234: D/BLZ20_WRAPPER(8165): blz20_wrp_close: std close (69)
01-29 10:22:00.244: I/BLZ20_WRAPPER(8165): blz20_wrp_close: s 68
01-29 10:22:00.244: D/BLZ20_WRAPPER(8165): blz20_wrp_close: std close (68)
01-29 10:22:00.244: I/BLZ20_WRAPPER(8165): blz20_wrp_close: s 67
01-29 10:22:00.244: D/BLZ20_WRAPPER(8165): blz20_wrp_close: fd (-1:67), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
01-29 10:22:00.244: I/BLZ20_WRAPPER(8165): __close_prot_rfcomm: fd 67
01-29 10:22:00.244: I/BTL_IFC(8165): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_BTS_RFC_CLOSE (BTS) 8 pbytes (hdl 66)
01-29 10:22:00.244: D/BTL_IFC_WRP(8165): wrp_close_s_only: wrp_close_s_only [67] (67:-1) []
01-29 10:22:00.244: D/BTL_IFC_WRP(8165): wrp_close_s_only: data socket closed
01-29 10:22:00.244: D/BTL_IFC_WRP(8165): wsactive_del: delete wsock 67 from active list [ad40f904]
01-29 10:22:00.244: D/BTL_IFC_WRP(8165): wrp_close_s_only: wsock fully closed, return to pool
01-29 10:22:00.244: D/BLZ20_WRAPPER(8165): btsk_free: success
At present, the best course of action that I see is to design my code so that if the .createRfcommSocketToServiceRecord()
method immediately fails with the "unable to start discovery" exception then to fall back to the relection method which, until today, I have never needed to use.
Additional information: My application targets API level 8. Suspecting that the RFCOMM connect bug affects Android 2.2 and below, I tried switching to API level 10 just to see if it would have any effect on the behaviour of .createRfcommSocketToServiceRecord()
, but the problem persisted: attempts to connect to the one Linvor module resulted in immediate IOException as described above.
Thanks - Trev
2
Answers
Struggling the same problem. Using API 10 on 2 phones. Both with Android 4.0.4.
One phone constantly failing with “Unable to start discovery” but works with reflection.
Second phone giving “Permission denied” with reflection but works with createRfcommSocketToServiceRecord().
And for research I checked android sources.
So it fails here in BluetoothSocket.java:
But fetchRemoteUuids() has many fail points and no, they don’t throw exceptions just return false.
BluetoothService.java:
Either native methods fail which leads us to drivers? Or “uuid is already in progress” part fails, because I don’t see even a try to connect/scan uuid, just instantly getting exception.
Linvor 1.8 here.
I struggle with this device a lot. Your particular problem is one of the issues I encountered.
It can be resolved by pulling the reset pin down (jump the pin to GND with jumper wire) when the device is fully powered.
The reset pin is the 3rd pin from the bottom left of the device.
For me this will allow me to connect to the device once without reflection, but it can go back to the bad behavior again.
My suggestion is that you implement watchdog ping from android to the device and trigger reset command with the remaining GPIO pin when the timer reached.
As for why and what triggered the behavior. I still don’t know, but hopefully someone will figure it out.
My suspect is that the device got stuck in an unknown state.