Android Tablets Forum banner
1 - 20 of 24 Posts

·
Registered
Joined
·
130 Posts
To keep things organized, I'm starting a new thread for the Android side of things. In thread http://www.slatedroid.com/topic/22388-kernel-discussion-for-fview-7-pro-tablet/ we got the compiling of Linux kernel modules working by lots of detective work on structure sizes and trial and error. Next step is to get Android to use the USB-connected & bluetooth-connected devices, so Android can start to use a bluetooth-connected 3G or GPS or a USB-connected 3G or GPS.

I'll tell you what I've found out so far for my Lanyu 910:

* 3G: rild (/system/bin/rild) is the program handling communications
* 3G: /data/local.prop can be used to set persistent (will be set after boot) properties related to the 3G modem. I've tried:

Code:
rild.libargs="-d /dev/ttyACM0"<br />
rild.libpath=/system/lib/libreference-ril.so
which should tell Android (rild to be more specific) what device to use and what library to use to access it.

* 3G: to restart rild, you can find out the process number, then kill it with "kill <number>", then start with "start rild"
* BT: /system/bin/bluetoothd exists and is running, can be restarted like rild
* BT: no bluetooth settings on Lanyu UI; there are settings for wired ethernet, even though the device doesn't have the hardware, so this may be a case of missing Android files or incorrect setup
* GPS: no GPS settings on Lanyu UI; there are settings for wired ethernet, even though the device doesn't have the hardware. I'm told the X10 Airpad software does have GPS settings, although that too doesn't have GPS hardware, so both suggest this may be a case of missing Android files or setup having swithed GPS off.
* much of Android firmware seems to reside at /system/framework
* BT: framework-res.jar does contain something bluetooth-related, e.g. res/drawable-hdpi/stat_sys_data_bluetooth.png
* BT: there's /system/lib/libbluedroid.so, /system/lib/libbluetoothd.so and /lib/libbluetooth.so
* 3G: The device (Lanyu 910) does have Android support for a 3G modem, and a Huawei 3G modem (will show up as ttyUSB0) will work like on an Android phone (except probably no phone calls)
* 3G: after setting properties so it users ttyACM0 instead of ttyUSB0 (the Rockchip initial config), the Nokia phone at ttyACM0 is not automatically found like the Huawei modem is found
* BT: "bttest enable" returns 0, which seems to mean at least partial success.

Some more notes / summarize a bit:

* I haven't yet got any of the devices tested working under Android (well, except for kind of the 3G phone, which works when connection is started under Ubuntu and DNS is set manually)
* It seems like the contents of the system partition will be needed to be changed to get GPS working

How to change the system partition, two approaches I'm considering (system.img is cramfs, so read-only and can't be mounted read-write unlike on many other tablets and phones)

* reflash modified system.img (if it'd be changed to be yaffs2, it could be mounted rw after that, that would also require changing boot.img)
* reflash only boot.img (compressed cpio) so the device will use some other partition as /system file system, not the cramfs. This approach sounds tempting, and is described at http://www.slatedroid.com/topic/22162-writable-system-for-rk29xxt760p71-et/ - might also modify that to drop in a possibility for dual-boot Android/Ubuntu or triple-boot Android/Ubuntu/Ångström (plus throw in one more option to boot the original system)
 

·
Registered
Joined
·
106 Posts
Ill will be trying to add Bluetoot GPS
on the linux side it seem to work
* rfcomm bind hci0 :mac: followed by cat /dev/rfcomm0 wil show NMEA data from my BTGPS
* bluetoothd is running

There are some BTGPS moc providers in the market, but they all fail
* or they report there is no BT avaiable
* or they say i should enable BT
* or they try to activate BT and wait forever afterward.

Next on my list is trying to find out what modification migh be needed for android to have enable/disable BT support
This might take a while, because ill be also busy on getting a console version of php running
 

·
Registered
Joined
·
130 Posts
Discussion Starter · #3 ·
A guess: Could be something to do with Android is checking hciattach existence / failure and stopping when it notices hciattach doesn't do anything useful.

possible pointers to solutions:

http://groups.google.com/group/android-porting/browse_thread/thread/0ad1219ae68a3642/86ccd62f90b039c9

http://www.androiddiscuss.com/1-android-discuss/18296.html

For me, CONFIG_RFKILL=y in linux .config solved the empty /sys/class/rfkill dir problem ... or so I thought until I read the messages linked in the above thread. According to the above link, another rfkill entry should exist and thus apparently rfkill functionality should be added to the btusb.c driver.

There are some BTGPS moc providers in the market, but they all fail
* or they report there is no BT avaiable
* or they say i should enable BT
* or they try to activate BT and wait forever afterward.
 

·
Registered
Joined
·
130 Posts
I noticed it's possible to do bind mounts on single files:

Code:
<br />
# busybox mount -o bind /data/mnt/android/init.rc /init.rc<br />
Helps in getting around the read only filesystem limitation.

UPDATE: This doesn't seem to be working consistently always, perhaps due to caching or perhaps more probably due to renaming ; old version is sometimes shown in favor of the current, probably if the editor used renames the edited file when writing.
 

·
Registered
Joined
·
106 Posts
I noticed it's possible to do bind mounts on single files:

Code:
<br />
# busybox mount -o bind /data/mnt/android/init.rc /init.rc<br />
Helps in getting around the read only filesystem limitation.

UPDATE: This doesn't seem to be working consistently always, perhaps due to caching or perhaps more probably due to renaming ; old version is sometimes shown in favor of the current, probably if the editor used renames the edited file when writing.
I believe the initrd file is unpacked into ram at time of boot.
The boot process in init.rc remount / as readonly somewhere along the line
You can use busybox mount -o remount,rw / to make root rw
Any changes will stay untill next reboot

And of course changing /system (with is cramfs) doesnt work.
 

·
Registered
Joined
·
106 Posts
* hcattach is working
* the rfkill directory with file entries is avaleble
* when an apps tries to enable BT, hcitool dev will show the device mac for a short time and bluetoothd process is runnig for a short time
so BT is actualy being enabled and then fails

logcat shows:

D/BluetoothService( 106): Bluetooth state 10 -> 11
V/BluetoothEventRedirector( 4456): Received android.bluetooth.adapter.action.STATE_CHANGED
I/ActivityManager( 106): Start proc com.android.bluetooth for broadcast com.android.bluetooth/.pbap.BluetoothPbapReceiver: pid=446
I/ActivityThread( 4466): Pub com.android.bluetooth.opp: com.android.bluetooth.opp.BluetoothOppProvider
I/bluedroid( 106): Starting hciattach daemon
I/bluedroid( 106): Starting bluetoothd deamon
E/BluetoothEventLoop.cpp( 106): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)
E/BluetoothEventLoop.cpp( 106): failure setting up Event Loop!
E/BluetoothEventLoop.cpp( 106): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)
E/BluetoothEventLoop.cpp( 106): failure setting up Event Loop!
D/BluetoothService( 106): bt EnableThread giving up
I/bluedroid( 106): Stopping bluetoothd deamon
I/bluedroid( 106): Stopping hciattach deamon
D/BluetoothService( 106): Bluetooth state 11 -> 10
V/BluetoothEventRedirector( 4456): Received android.bluetooth.adapter.action.STATE_CHANGED

Some process should be started by dbus witch failes or is not configure
Atm im trying to find out what the exact problem is
- what process needs to be started
- what program file contains is
- where is it configure what to start
 

·
Registered
Joined
·
106 Posts
Just as confirmation the following usb workt outofthe box on the original rom
* usb memory sticks
* some usb UMTS/GPRS data dongles (and internet over them works for the supported dongles)
* usb harddrives if they have external power

The sunplus.ko driver for USB 2.4ghz wirless keyboard can be compiled and works. [trust 16903 keyboard&mouse]
Other wireless kb drivers seem to be availeble to, but i havn't tries them.
 

·
Registered
Joined
·
130 Posts
Discussion Starter · #8 ·
Here's output from my bluetooth test. I inserted the modules, and then checked with "bttest enable", it outputs "0". I don't have bluetooth in the settings menu, so I can't test switch BT on in settings, but with "share" from browser there's a possiblity to turn BT on. When I open the share function in the browser, and answer "Yes" to the question of whether to turn bluetooth on, a message "Turning on bluetooth" or something like that appears for a while, then disappears, and I get the following in adb logcat. The message about permission denied is apparently from bluedroid.so. /sys/class/rfkill/rfkill0/state exists, and after I change the modes so write permission is enabled for all, I get a different message, see below the second logcat excerpt.

Code:
<br />
D/BluetoothService( 3229): Bluetooth state 10 -> 11<br />
E/bluedroid( 3229): open(/sys/class/rfkill/rfkill0/state) for write failed: Permission denied (13)<br />
D/BluetoothService( 3229): Bluetooth state 11 -> 10<br />
W/ActivityManager( 3229): Permission denied: checkComponentPermission() reqUid=1000<br />
W/ActivityManager( 3229): Permission Denial: broadcasting Intent { act=android.bluetooth.adapter.action.STATE_CHANGED flg=0x10000000 (has extras) } from android (pid=4203, uid=10049) requires null due to receiver com.android.settings/com.android.settings.widget.SettingsAppWidgetProvider<br />
V/testlauncher( 3229): start : com.android.bluetooth ;version: 9<br />
I/ActivityManager( 3229): Starting: Intent { flg=0x10000000 cmp=com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity } from pid 4203<br />
V/ActivityManager( 3229): Resuming HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Skip resume: need to start pausing<br />
V/ActivityManager( 3229): Resuming HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Resuming top, waiting visible to hide: HistoryRecord{408de318 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Launching: HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity} icicle=null with results=null newIntents=null andResume=true<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
D/dalvikvm( 4203): GC_EXTERNAL_ALLOC freed 542K, 55% free 2645K/5831K, external 1012K/1051K, paused 134ms<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{407ac898 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Checking to restart com.android.bluetooth.opp.BluetoothOppBtEnablingActivity: changed=0x0, handles=0x0, newConfig={ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=2 layout=35 uiMode=17 seq=13}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
I/ActivityManager( 3229): Displayed com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity: +63ms<br />
V/ActivityManager( 3229): Removing activity: token=HistoryRecord{408de318 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}, app=com.android.bluetooth<br />
I/ActivityManager( 3229): Destroying: HistoryRecord{408de318 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
D/dalvikvm( 3229): GC_CONCURRENT freed 1423K, 44% free 5498K/9735K, external 2865K/3623K, paused 3ms+6ms<br />
D/dalvikvm( 4177): GC_EXPLICIT freed 55K, 52% free 2849K/5895K, external 1006K/1518K, paused 50ms<br />
I/Lights  ( 3229): >>> Enter set_buttons_light<br />
After changing rfkill modes to world-writable:

Code:
<br />
D/BluetoothService( 3229): Bluetooth state 10 -> 11<br />
V/BluetoothEventRedirector( 4177): Received android.bluetooth.adapter.action.STATE_CHANGED<br />
W/ActivityManager( 3229): Permission denied: checkComponentPermission() reqUid=1000<br />
W/ActivityManager( 3229): Permission Denial: broadcasting Intent { act=android.bluetooth.adapter.action.STATE_CHANGED flg=0x10000000 (has extras) } from android (pid=4203, uid=10049) requires null due to receiver com.android.settings/com.android.settings.widget.SettingsAppWidgetProvider<br />
V/testlauncher( 3229): start : com.android.bluetooth ;version: 9<br />
I/ActivityManager( 3229): Starting: Intent { flg=0x10000000 cmp=com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity } from pid 4203<br />
V/ActivityManager( 3229): Resuming HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Skip resume: need to start pausing<br />
V/ActivityManager( 3229): Resuming HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Resuming top, waiting visible to hide: HistoryRecord{4083a790 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Launching: HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity} icicle=null with results=null newIntents=null andResume=true<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Checking to restart com.android.bluetooth.opp.BluetoothOppBtEnablingActivity: changed=0x0, handles=0x0, newConfig={ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=2 layout=35 uiMode=17 seq=13}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
I/ActivityManager( 3229): Displayed com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity: +480ms<br />
V/ActivityManager( 3229): Removing activity: token=HistoryRecord{4083a790 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}, app=com.android.bluetooth<br />
I/ActivityManager( 3229): Destroying: HistoryRecord{4083a790 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
I/bluedroid( 3229): Starting hciattach daemon<br />
I/WindowManager( 3229): Setting rotation to 1, animFlags=0<br />
I/ActivityManager( 3229): Config changed: { scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=1 layout=35 uiMode=17 seq=14}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Checking to restart com.android.bluetooth.opp.BluetoothOppBtEnablingActivity: changed=0x80, handles=0x0, newConfig={ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=1 layout=35 uiMode=17 seq=14}<br />
V/ActivityManager( 3229): Switch is restarting resumed HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Relaunching: HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity} with results=null newIntents=null andResume=true<br />
I/ActivityManager( 3229): Switch is restarting resumed HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
W/com.skype.raider.MainApp( 3577): onConfigurationChanged changed:{ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=1 layout=35 uiMode=17 seq=14}<br />
D/dalvikvm( 3229): GC_CONCURRENT freed 1648K, 45% free 5486K/9863K, external 2865K/3578K, paused 5ms+5ms<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4086f7b8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Checking to restart com.android.bluetooth.opp.BluetoothOppBtEnablingActivity: changed=0x0, handles=0x0, newConfig={ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=1 layout=35 uiMode=17 seq=14}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Checking to restart com.android.browser.BrowserActivity: changed=0x80, handles=0xa0, newConfig={ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=1 layout=35 uiMode=17 seq=14}<br />
D/dalvikvm( 3229): GC_EXPLICIT freed 72K, 45% free 5478K/9863K, external 2865K/3578K, paused 97ms<br />
I/Lights  ( 3229): >>> Enter set_buttons_light<br />
D/dalvikvm( 4177): GC_EXPLICIT freed 4K, 52% free 2849K/5895K, external 1006K/1518K, paused 49ms<br />
E/bluedroid( 3229): bt_enable: Timeout waiting for HCI device to come up<br />
D/BluetoothService( 3229): Bluetooth state 11 -> 10<br />
V/BluetoothEventRedirector( 4177): Received android.bluetooth.adapter.action.STATE_CHANGED<br />
 

·
Registered
Joined
·
130 Posts
Discussion Starter · #9 ·
When I shut down hci0 with:

hciconfig hci0 down

and after that try to switch BT on via browser, I seem to get a bit farther:

Code:
<br />
ting visible to hide: HistoryRecord{4088b290 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{405506e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{405506e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Launching: HistoryRecord{405506e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity} icicle=null with results=null newIntents=null andResume=true<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{405506e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{405506e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{405506e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Checking to restart com.android.bluetooth.opp.BluetoothOppBtEnablingActivity: changed=0x0, handles=0x0, newConfig={ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=2 layout=35 uiMode=17 seq=15}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
I/ActivityManager( 3229): Displayed com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity: +425ms<br />
V/ActivityManager( 3229): Removing activity: token=HistoryRecord{4088b290 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}, app=com.android.bluetooth<br />
I/ActivityManager( 3229): Destroying: HistoryRecord{4088b290 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
I/bluedroid( 3229): Starting hciattach daemon<br />
I/bluedroid( 3229): Starting bluetoothd deamon<br />
D/dalvikvm( 4238): GC_EXPLICIT freed 518K, 55% free 2676K/5831K, external 793K/1051K, paused 44ms<br />
E/BluetoothEventLoop.cpp( 3229): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 3229): failure setting up Event Loop!<br />
E/BluetoothEventLoop.cpp( 3229): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 3229): failure setting up Event Loop!<br />
D/BluetoothService( 3229): bt EnableThread giving up<br />
I/bluedroid( 3229): Stopping bluetoothd deamon<br />
I/Lights  ( 3229): >>> Enter set_buttons_light<br />
I/bluedroid( 3229): Stopping hciattach deamon<br />
D/BluetoothService( 3229): Bluetooth state 11 -> 10<br />
V/BluetoothEventRedirector( 4238): Received android.bluetooth.adapter.action.STATE_CHANGED<br />
D/dalvikvm( 4133): GC_EXPLICIT freed 1K, 49% free 3409K/6663K, external 793K/1051K, paused 47ms<br />
V/ActivityManager( 3229): Resuming HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Resuming top, waiting visible to hide: HistoryRecord{405506e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Resume running: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
W/InputManagerService( 3229): Window already focused, ignoring focus gain of: [email protected]<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
<br />
D/dalvikvm( 4203): GC_CONCURRENT freed 364K, 54% free 2698K/5831K, external 1037K/1320K, paused 3ms+4ms<br />
I/power   ( 3229): *** set_screen_state 0<br />
I/SensorsHal( 3229): [File] : hardware/rk29/sensor/MmaSensor.cpp; [Line] : 82; [Func] : enable() ; ! Info : newState = 0x0, what = 0x0, mEnabled = 0x1.<br />
I/SensorsHal( 3229): [File] : hardware/rk29/sensor/MmaSensor.cpp; [Line] : 97; [Func] : enable() ; ! Info : to call 'MMA_IOCTL_CLOSE'.<br />
I/vibrator( 3229): *** vibrator_off -2129643535<br />
I/vibrator( 3229): *** openTHE_DEVICE O_RDWR<br />
D/SurfaceFlinger( 3229): About to give-up screen, flinger = 0x94910<br />
D/skia    ( 3229): purging 196K from font cache [19 entries]<br />
I/WindowManager( 3229): Setting rotation to 0, animFlags=1<br />
D/dalvikvm( 3329): GC_CONCURRENT freed 486K, 54% free 2887K/6151K, external 1028K/1540K, paused 4ms+12ms<br />
D/dalvikvm( 3229): GC_EXPLICIT freed 1270K, 44% free 5566K/9863K, external 3537K/3578K, paused 92ms<br />
D/dalvikvm( 3326): GC_EXPLICIT freed 2K, 53% free 3164K/6663K, external 2751K/4012K, paused 42ms<br />
The lines:

Code:
<br />
I/bluedroid( 3229): Starting hciattach daemon<br />
I/bluedroid( 3229): Starting bluetoothd deamon<br />
D/dalvikvm( 4238): GC_EXPLICIT freed 518K, 55% free 2676K/5831K, external 793K/1051K, paused 44ms<br />
E/BluetoothEventLoop.cpp( 3229): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 3229): failure setting up Event Loop!<br />
E/BluetoothEventLoop.cpp( 3229): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 3229): failure setting up Event Loop!<br />
D/BluetoothService( 3229): bt EnableThread giving up<br />
I/bluedroid( 3229): Stopping bluetoothd deamon<br />
I/Lights  ( 3229): >>> Enter set_buttons_light<br />
I/bluedroid( 3229): Stopping hciattach deamon<br />
D/BluetoothService( 3229): Bluetooth state 11 -> 10<br />
look such that it's getting a bit more success.

What's the deal with hciattach? From some discussion I've gathered that hciattach is for uart-connected BT interfaces, and isn't needed when btusb.ko is used, and can cause conflicts with btusb.ko. Aiah's message about hciattach working however seems to be in conflict with this.

Noticed another thread on Slatedroid where getting btusb.ko bluetooth working is discussed, http://www.slatedroid.com/topic/18333-additional-kernel-modules-for-wm8650-tablets/ - will look into it.
 

·
Registered
Joined
·
130 Posts
Discussion Starter · #10 ·
On second thought, not sure if hci0 configged up (e.g. by "bttest enable") is still what gets the best results. The crucial line here appears to be:

Code:
<br />
E/bluedroid( 3229): bt_enable: Timeout waiting for HCI device to come up<br />
which comes from this code in bluedroid (current cyanogen, so not sure if the exact same source):

Code:
<br />
    LOGI("Starting hciattach daemon");<br />
    if (property_set("ctl.start", "hciattach") < 0) {<br />
        LOGE("Failed to start hciattach");<br />
        goto out;<br />
    }<br />
<br />
    // Try for 10 seconds, this can only succeed once hciattach has sent the<br />
    // firmware and then turned on hci device via HCIUARTSETPROTO ioctl<br />
    for (attempt = 1000; attempt > 0;  attempt--) {<br />
        hci_sock = create_hci_sock();<br />
        if (hci_sock < 0) goto out;<br />
<br />
        if (!ioctl(hci_sock, HCIDEVUP, HCI_DEV_ID)) {<br />
            break;<br />
        }<br />
        close(hci_sock);<br />
        usleep(10000);  // 10 ms retry delay<br />
    }<br />
which makes me suspect the trouble is with hciattach. Somewhere it was suggested to just recompile bluedroid with hciattach stuff disable to get bsusb BT working.

Code:
<br />
...<br />
<br />
d: checkComponentPermission() reqUid=1000<br />
W/ActivityManager( 3229): Permission Denial: broadcasting Intent { act=android.bluetooth.adapter.action.STATE_CHANGED flg=0x10000000 (has extras) } from android (pid=4203, uid=10049) requires null due to receiver com.android.settings/com.android.settings.widget.SettingsAppWidgetProvider<br />
V/testlauncher( 3229): start : com.android.bluetooth ;version: 9<br />
I/ActivityManager( 3229): Starting: Intent { flg=0x10000000 cmp=com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity } from pid 4203<br />
V/ActivityManager( 3229): Resuming HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Skip resume: need to start pausing<br />
V/ActivityManager( 3229): Resuming HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Resuming top, waiting visible to hide: HistoryRecord{40996ec0 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Launching: HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity} icicle=null with results=null newIntents=null andResume=true<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
D/dalvikvm( 3229): GC_CONCURRENT freed 1544K, 45% free 5518K/9863K, external 2865K/3578K, paused 4ms+13ms<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{409947e8 com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity}<br />
V/ActivityManager( 3229): Checking to restart com.android.bluetooth.opp.BluetoothOppBtEnablingActivity: changed=0x0, handles=0x0, newConfig={ scale=1.0 imsi=0/0 loc=en_GB touch=3 keys=1/1/2 nav=1/1 orien=2 layout=35 uiMode=17 seq=15}<br />
V/ActivityManager( 3229): Ensuring correct configuration: HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
V/ActivityManager( 3229): Configuration unchanged in HistoryRecord{4083cd68 com.android.browser/.BrowserActivity}<br />
I/ActivityManager( 3229): Displayed com.android.bluetooth/.opp.BluetoothOppBtEnablingActivity: +550ms<br />
V/ActivityManager( 3229): Removing activity: token=HistoryRecord{40996ec0 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}, app=com.android.bluetooth<br />
I/ActivityManager( 3229): Destroying: HistoryRecord{40996ec0 com.android.bluetooth/.opp.BluetoothOppBtEnableActivity}<br />
I/bluedroid( 3229): Starting hciattach daemon<br />
<br />
<br />
D/dalvikvm( 4238): GC_EXPLICIT freed 16K, 55% free 2674K/5831K, external 793K/1051K, paused 46ms<br />
I/Lights  ( 3229): >>> Enter set_buttons_light<br />
E/bluedroid( 3229): bt_enable: Timeout waiting for HCI device to come up<br />
D/BluetoothService( 3229): Bluetooth state 11 -> 10<br />
V/BluetoothEventRedirector( 4238): Received android.bluetooth.adapter.action.STATE_CHANGED<br />
 

·
Registered
Joined
·
130 Posts
Discussion Starter · #11 ·
One more variation - first "bttest enable" which outputs "0", then "hciconfig hci0 down", then try to switch BT on from browser share functions. bluetdroid hciattach start is passwd, but then trouble starts at dbus.

Code:
<br />
I/bluedroid( 3229): Starting hciattach daemon<br />
I/bluedroid( 3229): Starting bluetoothd deamon<br />
E/BluetoothEventLoop.cpp( 3229): setUpEventLoop: D-Bus error: org.freedesktop.DBus.Error.Disconnected (Connection was disconnected before a reply was received)<br />
E/BluetoothEventLoop.cpp( 3229): failure setting up Event Loop!<br />
E/BluetoothEventLoop.cpp( 3229): setUpEventLoop: D-Bus error: org.freedesktop.DBus.Error.Disconnected (Connection is closed)<br />
E/BluetoothEventLoop.cpp( 3229): failure setting up Event Loop!<br />
D/dalvikvm( 6261): GC_EXPLICIT freed 15K, 55% free 2674K/5831K, external 793K/1051K, paused 68ms<br />
D/BluetoothService( 3229): bt EnableThread giving up<br />
I/bluedroid( 3229): Stopping bluetoothd deamon<br />
I/bluedroid( 3229): Stopping hciattach deamon<br />
D/BluetoothService( 3229): Bluetooth state 11 -> 10<br />
V/BluetoothEventRedirector( 6261): Received android.bluetooth.adapter.action.STATE_CHANGED<br />
I/Lights  ( 3229): >>> Enter set_buttons_light<br />
 

·
Registered
Joined
·
106 Posts
View attachment init_system_rw.sh.gz

This scripts makes /system writable
- requires root
- no other firmware mods required (see notes)
- only tested it on fview 7"
- work in progress...

notes:
Changes to /system are semipermanent on, reboot the system will use the standard cramfs /system untill you run the script again

And with a small change to init.rc (does require firmware mod) you can have the script start automaticly (as early as possible)
init.rc mod (place is right after the service ueventd /sbin/ueventd critical entry)

service init_system_rw /init_system_rw.sh
user root
oneshot
 

Attachments

·
Registered
Joined
·
130 Posts
I've now managed to get Android to connect to bluetoothd when bluetoothd is started manually, which means the LY 910 seems to contain all the necessary parts at the Android side for bluetooth functionality. The bluetooth icon in upper toolbar comes up. However, bluetooth still can't be found in settings. Also, bluetooth from Android doesn't work, seems that bluetoothd doesn't really communicate with the hardware. Probably when started manually it's a problem with the sockets (/dev/socket/bluetooth and /dev/socket/dbus_bluetooth), there's a message bluetoothd[1909]: Unable to get the control socket for 'bluetooth'

The method to start bluetoothd manually, is to replace bluetoothd with a shell script which just sleeps, and start the real bluetoothd manually.

What I also do is run the follow when Android bluedroid runs hciconfig:

Code:
# echo 1 > /sys/class/rfkill/rfkill0/state ; hciconfig hci0 down ; hciconfig hci0 up
Otherwise, the startup goes
- insert modules: bluetooth, btusb, l2cap, rfcomm, bnep, sco
- hciconfig hci0 up
- chmod 777 /sys/class/rfkill/rfkill0/*
- browser / share / bluetooth

So, the problem with normal functionality seems to be now located to bluetoothd. I modified bluetoothd to write output to a file and start with -d -n, here's the output:

Code:
<br />
bluetoothd[1961]: Bluetooth deamon 4.69<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() parsing main.conf<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() discovto=120<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() pairto=0<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() pageto=8192<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() name=%m<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() class=0x40020C<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() discov_interval=0<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() deviceid=android:generic:1.5<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:parse_config() default_link_policy=7<br />
bluetoothd[1961]: Starting SDP server<br />
bluetoothd[1961]: Got Unix socket fd '12' from environment<br />
bluetoothd[1961]: Adding device id record for 000a:0000<br />
bluetoothd[1961]: external/bluetooth/bluez/src/plugin.c:plugin_init() Loading builtin plugins<br />
bluetoothd[1961]: external/bluetooth/bluez/src/plugin.c:add_plugin() Loading hciops plugin<br />
bluetoothd[1961]: external/bluetooth/bluez/src/plugin.c:plugin_init() Loading plugins /system/lib/bluez-plugin<br />
bluetoothd[1961]: external/bluetooth/bluez/src/plugin.c:add_plugin() Loading audio plugin<br />
bluetoothd[1961]: external/bluetooth/bluez/src/plugin.c:add_plugin() Loading input plugin<br />
bluetoothd[1961]: HCI dev 0 registered<br />
bluetoothd[1961]: external/bluetooth/bluez/plugins/hciops.c:init_device() child 1962 forked<br />
bluetoothd[1961]: external/bluetooth/bluez/src/adapter.c:btd_adapter_ref() 0x10dd8: ref=1<br />
bluetoothd[1961]: HCI dev 0 up<br />
bluetoothd[1961]: Starting security manager 0<br />
bluetoothd[1961]: Can't read version info for /org/bluez/1961/hci0: Connection timed out (110)<br />
bluetoothd[1961]: external/bluetooth/bluez/src/main.c:main() Entering main loop<br />
bluetoothd[1961]: external/bluetooth/bluez/plugins/hciops.c:child_exit() child 1962 exited<br />
bluetoothd[1961]: external/bluetooth/bluez/src/rfkill.c:rfkill_event() RFKILL event idx 0 type 2 op 0 soft 0 hard 0<br />
bluetoothd[1961]: external/bluetooth/bluez/src/adapter.c:adapter_remove() Removing adapter /org/bluez/1961/hci0<br />
Meanwhile, the problematic lines at adb logcat output are:

Code:
<br />
I/bluedroid( 1141): Starting hciattach daemon<br />
I/bluedroid( 1141): Starting bluetoothd deamon<br />
D/dalvikvm( 1653): GC_EXPLICIT freed 4K, 52% free 2603K/5379K, external 793K/1051K, paused 35ms<br />
I/Lights  ( 1141): >>> Enter set_buttons_light<br />
E/BluetoothEventLoop.cpp( 1141): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 1141): failure setting up Event Loop!<br />
E/BluetoothEventLoop.cpp( 1141): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 1141): failure setting up Event Loop!<br />
D/dalvikvm( 1775): GC_EXPLICIT freed 16K, 52% free 2835K/5895K, external 1182K/1640K, paused 58ms<br />
D/BluetoothService( 1141): bt EnableThread giving up<br />
Or, perhaps it's a level problem anyway, the following line would seem to point to that:

Code:
Can't read version info for /org/bluez/1961/hci0: Connection timed out (110)
In Cyanogenmod, that matches to cyanogenmod/external/bluetooth/bluez/test/lmptest.c - and after this, bluetoothd does exit(), so that seems to be the problem.

Code:
<br />
	if (hci_read_local_version(dd, &ver, 1000) < 0) {<br />
		fprintf(stderr, "Can't read version for hci%d: %s (%d)\n",<br />
						dev, strerror(errno), errno);<br />
		hci_close_dev(dd);<br />
		exit(1);<br />
	}
Version request is in bluez/lib/hci.c:

Code:
<br />
	rq.ogf    = OGF_INFO_PARAM;<br />
	rq.ocf    = OCF_READ_LOCAL_COMMANDS;<br />
	rq.rparam = &rp;<br />
	rq.rlen   = READ_LOCAL_COMMANDS_RP_SIZE;<br />
<br />
	if (hci_send_req(dd, &rq, to) < 0)<br />
		return -1;
UPDATE: This is a low-level problem which exists also on the Linux side:

Code:
<br />
[email protected]:/android/bin# hciconfig hci0  version<br />
Can't read version info hci0: Connection timed out (110)<br />
[email protected]:/android/bin# <br />
This means that if I get that one solved, bluetooth will probably start working. At least one remaining problem is there's no Bluetooth setup at the normal android settings, but a workaround for that is that BT setup can be entered via a program which uses bluetooth.
 

·
Registered
Joined
·
106 Posts
Im having the same problem
* hciconfig hci0 version (followed by the timeout)
same for
* hciconfig -a

i think the timeout occurs on
bluez/hci.c function hci_send_req(.....

Code:
<br />
                        p.fd = dd; p.events = POLLIN;<br />
                        while ((n = poll(&p, 1, to)) < 0) {<br />
                                if (errno == EAGAIN || errno == EINTR)<br />
                                        continue;<br />
                                LOGD("hci_send_req poll fail [%d]\n",errno);<br />
                                goto failed;<br />
                        }<br />
<br />
                        if (!n) {<br />
                                errno = ETIMEDOUT;<br />
                                LOGD("hci_send_req poll fail/to\n");<br />
                                goto failed;<br />
                        }<br />
Its the ETIMEOUT that occurs in my case.

- poll is waiting for data to apear on the filedescriptor and timeouts
- the poll is preseeded by getsockopt and hci_send_cmd boat complete successfull

so why is poll failing
- btusb.ko is still wrong (and not returing data)
- the hci_send_cmd seems to set some filters (and the correct filter is missing)

I compared hci.c with hci.c from ubutu 10.4 and there doesn't seem to be any relevant difference.
On ubuntu 10.4 with nieuwe bluez version and 2.7.32.32 btusb is working
 

·
Registered
Joined
·
130 Posts
As you're having the same problem with kernel-internal bluetooth instead of bluetooth.ko, it perhaps isn't struct size difference cause by kernel config difference which I thought it was.

It seems to me poll is failing as the data does not come back from kernel to the socket, but not really sure what's going on. I added some debug messages, and here's a dmesg log from hciconfig hci0 version - rx_task gets called, but the values don't seem right to me (it's a STATUS message):

Code:
<br />
<7>[ 5283.383836] hci_sock_create: sock d2b68240<br />
<7>[ 5283.383943] hci_sock_ioctl: cmd 800448d3 arg 2a01e20c<br />
<7>[ 5283.383962] hci_dev_get: 0<br />
<7>[ 5283.384056] hci_sock_create: sock d2b13240<br />
<7>[ 5283.384096] hci_sock_bind: sock d2b13240 sk c9327200<br />
<7>[ 5283.384111] hci_dev_get: 0<br />
<7>[ 5283.384154] hci_sock_setsockopt: sk c9327200, opt 2<br />
<7>[ 5283.384192] hci_sock_sendmsg: sock d2b13240 sk c9327200<br />
<7>[ 5283.384243] hci_cmd_task: hci0 cmd 1<br />
<7>[ 5283.384270] hci_send_frame: hci0 type 1 len 3<br />
<7>[ 5283.384288] hci_send_to_sock: hdev raw d200d000 len 3<br />
<7>[ 5283.386773] hci_rx_task: hci0<br />
<7>[ 5283.386790] hci_rx_task: hci0 promisc: 0x1<br />
<7>[ 5283.386806] hci_send_to_sock: hdev raw d200d000 len 6<br />
<7>[ 5283.386821] hci_rx_task: hci0 event packet<br />
<7>[ 5283.386836] hci_cmd_status_evt: hci0 ev->status 0x1<br />
<7>[ 5283.386849] hci_cmd_status_evt: hci0 ev->ncmd 0x1<br />
<7>[ 5283.386862] hci_cmd_status_evt: hci0 ev->opcode 0x101<br />
<7>[ 5283.386876] hci_cmd_status_evt: hci0 opcode 0x101<br />
<7>[ 5283.386890] hci_cmd_status_evt: hci0 opcode 0x101<br />
<7>[ 5283.386904] hci_event_packet: hci0 non-default event 0xf<br />
Is the promisc flag supposed to be on?

A strange thing also is that the timeout also happens when hci0 is down, here's the log from that case:

Code:
<br />
<7>[ 5494.976665] hci_sock_create: sock d2b13240<br />
<7>[ 5494.976771] hci_sock_ioctl: cmd 800448d3 arg 2a01e20c<br />
<7>[ 5494.976790] hci_dev_get: 0<br />
<7>[ 5494.976880] hci_sock_create: sock d2b68240<br />
<7>[ 5494.976920] hci_sock_bind: sock d2b68240 sk c9327200<br />
<7>[ 5494.976935] hci_dev_get: 0<br />
<7>[ 5494.976976] hci_sock_setsockopt: sk c9327200, opt 2<br />
<7>[ 5494.977015] hci_sock_sendmsg: sock d2b68240 sk c9327200<br />
<7>[ 5494.977067] hci_cmd_task: hci0 cmd 1<br />
<7>[ 5494.977088] hci_send_frame: hci0 type 1 len 3<br />
<7>[ 5494.977106] hci_send_to_sock: hdev raw d200d000 len 3<br />
<4>[ 5494.978957] adb_write<br />
<4>[ 5494.979000] adb_write<br />
<4>[ 5494.980902] adb_read<br />
<7>[ 5495.978272] hci_sock_setsockopt: sk c9327200, opt 2<br />
<7>[ 5495.978974] hci_sock_release: sock d2b13240 sk c9327000<br />
<7>[ 5495.979024] hci_sock_release: sock d2b68240 sk c9327200<br />
.. but maybe that isn't strange actually, as the timeout is just a message that nothing is coming back from the socket, and in this cases _rx isn't even called. Perhaps I should also debug on the x86 laptop with the same debug output, to see what the normal course of events is.

One thing which happens with some ops is a tx timeout, here's output from hciconcfig hci0 features:

Code:
<br />
<7>[ 5681.973581] hci_sock_create: sock d2b13240<br />
<7>[ 5681.973687] hci_sock_ioctl: cmd 800448d3 arg 2a01e20c<br />
<7>[ 5681.973706] hci_dev_get: 0<br />
<7>[ 5681.973801] hci_sock_create: sock d2b68240<br />
<7>[ 5681.973840] hci_sock_bind: sock d2b68240 sk cc2e2c00<br />
<7>[ 5681.973856] hci_dev_get: 0<br />
<7>[ 5681.973910] hci_sock_setsockopt: sk cc2e2c00, opt 2<br />
<7>[ 5681.973950] hci_sock_sendmsg: sock d2b68240 sk cc2e2c00<br />
<7>[ 5681.974002] hci_cmd_task: hci0 cmd 0<br />
<3>[ 5681.974015] hci_cmd_task: hci0 command tx timeout<br />
<3>[ 5681.975864] hci_cmd_task: hci0 command tx cmd_last_tx 535820 jiffies HZ: 538197: 512 <br />
<7>[ 5681.983725] hci_send_frame: hci0 type 1 len 4<br />
<7>[ 5681.983744] hci_send_to_sock: hdev raw d200d000 len 4<br />
<4>[ 5681.984087] adb_write<br />
<4>[ 5681.985929] adb_write<br />
<4>[ 5681.988431] adb_read<br />
<7>[ 5682.988694] hci_sock_setsockopt: sk cc2e2c00, opt 2<br />
<7>[ 5682.989345] hci_sock_release: sock d2b13240 sk cc2e2a00<br />
<7>[ 5682.989394] hci_sock_release: sock d2b68240 sk cc2e2c00<br />
<br />
 

·
Registered
Joined
·
106 Posts
I cant check the hci parts themeself, because hci and bluetooth are already included in the kernel on the fview (only btusb and some obscure bt prococols where not)

Also the receiving part cant be all wrong because if i manualy do rfcomm bind hci0 ::mac-addrss::. and cat /dev/rfcomm0 i do receive data from my bt-gps device.
 

·
Registered
Joined
·
130 Posts
Im having the same problem
* hciconfig hci0 version (followed by the timeout)
same for
* hciconfig -a
Hmm, odd that hciconfig -a doesn't work for you - it works fine for me:

Code:
#   hciconfig -a<br />
hci0:   Type: BR/EDR  Bus: USB<br />
        BD Address: 00:0D:B5:xx:xx:xx  ACL MTU: 384:8  SCO MTU: 64:8<br />
        DOWN <br />
        RX [URL=bytes:17824]bytes:17824[/URL] [URL=acl:24]acl:24[/URL] [URL=sco:0]sco:0[/URL] [URL=events:527]events:527[/URL] errors:0<br />
        TX [URL=bytes:2248]bytes:2248[/URL] [URL=acl:18]acl:18[/URL] [URL=sco:0]sco:0[/URL] [URL=commands:500]commands:500[/URL] errors:0<br />
        Features: 0xff 0xff 0x8f 0xfe 0x9b 0xf9 0x00 0x80<br />
        Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3 <br />
        Link policy: RSWITCH HOLD SNIFF <br />
        Link mode: SLAVE ACCEPT <br />
dmesg debug:

Code:
<br />
<4>[ 6363.599044] adb_write<br />
<4>[ 6363.599088] adb_write<br />
<7>[ 6363.600846] hci_sock_ioctl: cmd 800448d2 arg 17120<br />
<7>[ 6363.600873] hci_sock_ioctl: cmd 800448d3 arg 16234<br />
<7>[ 6363.600889] hci_dev_get: 0<br />
<4>[ 6363.600967] adb_read<br />
<7>[ 6363.604015] hci_sock_release: sock d2bd56c0 sk c516ae00
and with hci0 up:

Code:
<br />
#   hciconfig -a<br />
hci0:   Type: BR/EDR  Bus: USB<br />
        BD Address: 00:0D:B5:xx:xx:xx  ACL MTU: 384:8  SCO MTU: 64:8<br />
        UP RUNNING PSCAN <br />
        RX [URL=bytes:18188]bytes:18188[/URL] [URL=acl:24]acl:24[/URL] [URL=sco:0]sco:0[/URL] [URL=events:540]events:540[/URL] errors:0<br />
        TX [URL=bytes:2293]bytes:2293[/URL] [URL=acl:18]acl:18[/URL] [URL=sco:0]sco:0[/URL] [URL=commands:513]commands:513[/URL] errors:0<br />
        Features: 0xff 0xff 0x8f 0xfe 0x9b 0xf9 0x00 0x80<br />
        Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3 <br />
        Link policy: RSWITCH HOLD SNIFF <br />
        Link mode: SLAVE ACCEPT <br />
Can't read local name on hci0: Connection timed out (110)<br />
Ahh, I see, there's the timeout - in getting local name. There does seem to be status packet.

Code:
<br />
<7>[ 6413.353265] hci_sock_create: sock d2bd5240<br />
<7>[ 6413.353324] hci_sock_ioctl: cmd 800448d2 arg 17120<br />
<7>[ 6413.353348] hci_sock_ioctl: cmd 800448d3 arg 16234<br />
<7>[ 6413.353364] hci_dev_get: 0<br />
<7>[ 6413.353948] hci_sock_create: sock d2bd53c0<br />
<7>[ 6413.353983] hci_sock_bind: sock d2bd53c0 sk c9327200<br />
<7>[ 6413.353998] hci_dev_get: 0<br />
<7>[ 6413.354025] hci_sock_setsockopt: sk c9327200, opt 2<br />
<7>[ 6413.354054] hci_sock_sendmsg: sock d2bd53c0 sk c9327200<br />
<7>[ 6413.354090] hci_cmd_task: hci0 cmd 1<br />
<7>[ 6413.354113] hci_send_frame: hci0 type 1 len 3<br />
<7>[ 6413.354132] hci_send_to_sock: hdev raw d200d000 len 3<br />
<7>[ 6413.356773] hci_rx_task: hci0<br />
<7>[ 6413.356789] hci_rx_task: hci0 promisc: 0x1<br />
<7>[ 6413.356804] hci_send_to_sock: hdev raw d200d000 len 10<br />
<7>[ 6413.356819] hci_rx_task: hci0 event packet<br />
<7>[ 6413.356836] hci_cmd_complete_evt: hci0 opcode 0x1401<br />
<7>[ 6413.356850] hci_cmd_complete_evt: hci0 non-default opcode 0x1401<br />
<7>[ 6413.356866] hci_event_packet: hci0 non-default event 0xe<br />
<4>[ 6413.358885] adb_write<br />
<4>[ 6413.358920] adb_write<br />
<4>[ 6413.360825] adb_read<br />
<4>[ 6414.298634] eboda zlj add for test 110616 Bat_Ocv_Vol:=4185<br />
<4>[ 6414.301368] eboda zlj add for test 110616 rt_rest_vol:=100<br />
<4>[ 6414.306823] eboda zlj add for test 110616 ocv_rest_vol1:=100<br />
<4>[ 6414.312500] eboda zlj add for test 110616  charger->rest_vol1:=100<br />
<4>[ 6414.318638] eboda zlj add for test 110616  charger->rest_vol2:=100<br />
<4>[ 6414.324765] eboda zlj add for test 110616  charger->rest_vol3:=99, pre_rest_vol=99<br />
<7>[ 6414.355261] hci_sock_setsockopt: sk c9327200, opt 2<br />
<7>[ 6414.355958] hci_sock_release: sock d2bd5240 sk c9327000<br />
<7>[ 6414.356012] hci_sock_release: sock d2bd53c0 sk c9327200<br />
I've even modified bluetoothd & libraries to ignore the timeout, but still there's a problem with adapter not found, don't know what that problem is, as bluetoothd does seem to register the adapter:

Code:
<br />
bluetoothd[1921]: Bluetooth deamon 4.93<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() parsing main.conf<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() discovto=120<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() pairto=0<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() pageto=8192<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() name=%m<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() class=0x40020C<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() discov_interval=0<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() deviceid=android:generic:1.5<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:parse_config() default_link_policy=7<br />
bluetoothd[1921]: Starting SDP server<br />
bluetoothd[1921]: Got Unix socket fd '12' from environment<br />
bluetoothd[1921]: Adding device id record for 000a:0000<br />
bluetoothd[1921]: external/bluetooth/bluez/src/plugin.c:plugin_init() Loading builtin plugins<br />
bluetoothd[1921]: external/bluetooth/bluez/src/plugin.c:add_plugin() Loading mgmtops plugin<br />
bluetoothd[1921]: external/bluetooth/bluez/src/plugin.c:add_plugin() Loading service plugin<br />
bluetoothd[1921]: external/bluetooth/bluez/src/plugin.c:plugin_init() Loading plugins /system/lib/bluez-plugin<br />
bluetoothd[1921]: Can't load plugin /system/lib/bluez-plugin/audio.so: Cannot load library: reloc_library[1311]:  1921 cannot locate 'error_common_reply'...<br />
<br />
bluetoothd[1921]: Can't load plugin /system/lib/bluez-plugin/input.so: Cannot load library: reloc_library[1311]:  1921 cannot locate 'bt_acl_encrypt'...<br />
<br />
bluetoothd[1921]: external/bluetooth/bluez/plugins/service.c:register_interface() path /org/bluez/1921/any<br />
bluetoothd[1921]: external/bluetooth/bluez/plugins/service.c:register_interface() Registered interface org.bluez.Service on path /org/bluez/1921/any<br />
bluetoothd[1921]: external/bluetooth/bluez/src/main.c:main() Entering main loop<br />
bluetoothd[1921]: external/bluetooth/bluez/src/rfkill.c:rfkill_event() RFKILL event idx 0 type 2 op 0 soft 0 hard 0<br />
bluetoothd[1921]: external/bluetooth/bluez/src/plugin.c:plugin_cleanup() Cleanup plugins<br />
or from logcat:

Code:
<br />
I/bluedroid( 1195): Starting hciattach daemon<br />
I/bluedroid( 1195): Starting bluetoothd deamon<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()parsing main.conf<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()discovto=120<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()pairto=0<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()pageto=8192<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()name=%m<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()class=0x40020C<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()discov_interval=0<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()deviceid=android:generic:1.5<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:parse_config()default_link_policy=7<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/plugin.c:plugin_init()Loading builtin plugins<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/plugin.c:add_plugin()Loading mgmtops plugin<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/plugin.c:add_plugin()Loading service plugin<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/plugin.c:plugin_init()Loading plugins /system/lib/bluez-plugin<br />
E/Bluez   ( 1932): external/bluetooth/bluez/plugins/service.c:register_interface()path /org/bluez/1932/any<br />
E/Bluez   ( 1932): external/bluetooth/bluez/plugins/service.c:register_interface()Registered interface org.bluez.Service on path /org/bluez/1932/any<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/main.c:main()Entering main loop<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/rfkill.c:rfkill_event()RFKILL event idx 0 type 2 op 0 soft 0 hard 0<br />
E/BluetoothEventLoop.cpp( 1195): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 1195): failure setting up Event Loop!<br />
D/dalvikvm( 1748): GC_EXPLICIT freed 20K, 54% free 2760K/5895K, external 1006K/1051K, paused 48ms<br />
E/BluetoothEventLoop.cpp( 1195): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter)<br />
E/BluetoothEventLoop.cpp( 1195): failure setting up Event Loop!<br />
D/BluetoothService( 1195): bt EnableThread giving up<br />
I/bluedroid( 1195): Stopping bluetoothd deamon<br />
E/Bluez   ( 1932): external/bluetooth/bluez/src/plugin.c:plugin_cleanup()Cleanup plugins<br />
I/bluedroid( 1195): Stopping hciattach deamon<br />
D/BluetoothService( 1195): Bluetooth state 11 -> 10<br />
V/BluetoothEventRedirector( 1748): Received android.bluetooth.adapter.action.STATE_CHANGED<br />
 

·
Registered
Joined
·
130 Posts
Here's a dmesg log from "hciconfig hci0 version" with also btusb debug logging enabled.

Code:
<br />
<7>[ 8284.966629] hci_sock_create: sock d2bd5240<br />
<7>[ 8284.966695] hci_sock_ioctl: cmd 800448d3 arg 16234<br />
<7>[ 8284.966713] hci_dev_get: 0<br />
<7>[ 8284.966812] hci_sock_create: sock d2bd53c0<br />
<7>[ 8284.966844] hci_sock_bind: sock d2bd53c0 sk c5361c00<br />
<7>[ 8284.966859] hci_dev_get: 0<br />
<7>[ 8284.966897] hci_sock_setsockopt: sk c5361c00, opt 2<br />
<7>[ 8284.966929] hci_sock_sendmsg: sock d2bd53c0 sk c5361c00<br />
<7>[ 8284.966981] hci_cmd_task: hci0 cmd 1<br />
<7>[ 8284.967007] hci_send_frame: hci0 type 1 len 3<br />
<7>[ 8284.967027] hci_send_to_sock: hdev raw c503f800 len 3<br />
<7>[ 8284.967044] btusb_send_frame: hci0<br />
<7>[ 8284.968792] btusb_tx_complete: hci0 urb ceb8b940 status 0 count 3<br />
<7>[ 8284.969756] btusb_intr_complete: hci0 urb c706be40 status 0 count 6<br />
<7>[ 8284.969794] hci_rx_task: hci0<br />
<7>[ 8284.969808] hci_rx_task: hci0 promisc: 0x1<br />
<7>[ 8284.969822] hci_send_to_sock: hdev raw c503f800 len 6<br />
<7>[ 8284.969837] hci_rx_task: hci0 event packet<br />
<7>[ 8284.969852] hci_cmd_status_evt: hci0 ev->status 0x1<br />
<7>[ 8284.969865] hci_cmd_status_evt: hci0 ev->ncmd 0x1<br />
<7>[ 8284.969878] hci_cmd_status_evt: hci0 ev->opcode 0x101<br />
<7>[ 8284.969892] hci_cmd_status_evt: hci0 opcode 0x101<br />
<7>[ 8284.969906] hci_cmd_status_evt: hci0 opcode 0x101<br />
<7>[ 8284.969921] hci_event_packet: hci0 non-default event 0xf<br />
<7>[ 8285.968199] hci_sock_setsockopt: sk c5361c00, opt 2<br />
<4>[ 8285.968966] adb_write<br />
<4>[ 8285.969027] adb_write<br />
<7>[ 8285.971098] hci_sock_release: sock d2bd5240 sk c5361600<br />
<7>[ 8285.971145] hci_sock_release: sock d2bd53c0 sk c5361c00<br />
Do I understand correctly that the log shows a 3-byte event packet sent, then a 6-byte event packet received? The opcode seems something which is not recognized by hci_event.c
 

·
Registered
Joined
·
130 Posts
Discussion Starter · #19 ·
Also the receiving part cant be all wrong because if i manualy do rfcomm bind hci0 ::mac-addrss::. and cat /dev/rfcomm0 i do receive data from my bt-gps device.
Apparently there are different packet types (see hci_core.c: HCI_EVENT_PKT, HCI_ACLDATA_PKT and HCI_SCODATA_PKT). Seems the event packets relating to local device properties are problematic - version, revision, features, changing name. "sdptool browse address" passes some ACL data packets and some event packets and seems to work fine:

Code:
<br />
<7>[ 8718.221992] hci_send_frame: hci0 type 1 len 5<br />
<7>[ 8718.222005] btusb_send_frame: hci0<br />
<7>[ 8718.237986] btusb_tx_complete: hci0 urb c41a6840 status 0 count 5<br />
<7>[ 8718.238751] btusb_intr_complete: hci0 urb c706be40 status 0 count 5<br />
<7>[ 8718.238792] hci_rx_task: hci0<br />
<7>[ 8718.238805] hci_rx_task: hci0 event packet<br />
<7>[ 8718.238819] hci_event_packet: hci0 event 0x1b<br />
<7>[ 8718.238832] hci_event_packet: hci0 non-default event 0x1b<br />
<7>[ 8718.239755] btusb_intr_complete: hci0 urb c706be40 status 0 count 6<br />
<7>[ 8718.239785] hci_rx_task: hci0<br />
<7>[ 8718.239797] hci_rx_task: hci0 event packet<br />
<7>[ 8718.239810] hci_cmd_status_evt: hci0 ev->status 0x0<br />
<7>[ 8718.239823] hci_cmd_status_evt: hci0 ev->ncmd 0x0<br />
<7>[ 8718.239837] hci_cmd_status_evt: hci0 ev->opcode 0x41b<br />
<7>[ 8718.239850] hci_cmd_status_evt: hci0 opcode 0x41b<br />
<7>[ 8718.239865] hci_cs_read_remote_features: hci0 status 0x0<br />
<7>[ 8718.239879] hci_event_packet: hci0 non-default event 0xf<br />
<7>[ 8718.246751] btusb_intr_complete: hci0 urb c706be40 status 0 count 6<br />
<7>[ 8718.246780] hci_rx_task: hci0<br />
<7>[ 8718.246792] hci_rx_task: hci0 event packet<br />
<7>[ 8718.246804] hci_cmd_status_evt: hci0 ev->status 0x0<br />
<7>[ 8718.246817] hci_cmd_status_evt: hci0 ev->ncmd 0x1<br />
<7>[ 8718.246830] hci_cmd_status_evt: hci0 ev->opcode 0x0<br />
<7>[ 8718.246843] hci_cmd_status_evt: hci0 opcode 0x0<br />
<7>[ 8718.246856] hci_cmd_status_evt: hci0 opcode 0x0<br />
<7>[ 8718.246869] hci_event_packet: hci0 non-default event 0xf<br />
<7>[ 8718.254759] btusb_intr_complete: hci0 urb c706be40 status 0 count 13<br />
<7>[ 8718.254790] hci_rx_task: hci0<br />
<7>[ 8718.254802] hci_rx_task: hci0 event packet<br />
<7>[ 8718.254815] hci_remote_features_evt: hci0 status 0<br />
<7>[ 8718.254842] l2cap_connect_cfm: hcon c5361c00 bdaddr 9F:D6:AC:xx:xx:xx status 0<br />
<7>[ 8718.254860] l2cap_conn_ready: conn c41a6540<br />
<7>[ 8718.254882] l2cap_build_cmd: conn c41a6540, code 0x0a, ident 0x01, len 2<br />
<7>[ 8718.254900] l2cap_send_cmd: code 0x0a<br />
<7>[ 8718.254915] hci_send_acl: hci0 conn c5361c00 flags 0x0<br />
<7>[ 8718.254931] hci_send_acl: hci0 nonfrag skb cd679e40 len 14<br />
<7>[ 8718.254955] sco_connect_cfm: hcon c5361c00 bdaddr 9F:D6:AC:xx:xx:xx status 0<br />
<7>[ 8718.254973] hci_event_packet: hci0 non-default event 0xb<br />
<7>[ 8718.254992] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.255003] hci_sched_acl: hci0<br />
<7>[ 8718.255016] hci_low_sent: conn c5361c00 quote 8<br />
<7>[ 8718.255030] hci_sched_acl: skb cd679e40 len 14<br />
<7>[ 8718.255045] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.255060] hci_send_frame: hci0 type 2 len 14<br />
<7>[ 8718.255073] btusb_send_frame: hci0<br />
<7>[ 8718.255094] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.255106] hci_sched_sco: hci0<br />
<7>[ 8718.255118] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.255130] hci_sched_esco: hci0<br />
<7>[ 8718.255142] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.255813] btusb_tx_complete: hci0 urb c41a6840 status 0 count 14<br />
<7>[ 8718.261756] btusb_intr_complete: hci0 urb c706be40 status 0 count 7<br />
<7>[ 8718.261790] hci_rx_task: hci0<br />
<7>[ 8718.261802] hci_rx_task: hci0 event packet<br />
<7>[ 8718.261816] hci_num_comp_pkts_evt: hci0 num_hndl 1<br />
<7>[ 8718.261831] hci_event_packet: hci0 non-default event 0x13<br />
<7>[ 8718.261849] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.261860] hci_sched_acl: hci0<br />
<7>[ 8718.261872] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.261883] hci_sched_sco: hci0<br />
<7>[ 8718.261894] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.261906] hci_sched_esco: hci0<br />
<7>[ 8718.261917] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.288282] btusb_bulk_complete: hci0 urb c706b0c0 status 0 count 20<br />
<7>[ 8718.288323] hci_rx_task: hci0<br />
<7>[ 8718.288335] hci_rx_task: hci0 ACL data packet<br />
<7>[ 8718.288351] hci_acldata_packet: hci0 len 16 handle 0x2a flags 0x2<br />
<7>[ 8718.288368] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.288387] l2cap_recv_acldata: conn c41a6540 len 16 flags 0x2<br />
<7>[ 8718.288404] l2cap_recv_frame: len 12, cid 0x0001<br />
<7>[ 8718.288418] l2cap_raw_recv: conn c41a6540<br />
<7>[ 8718.288434] l2cap_sig_channel: code 0x0b len 8 id 0x01<br />
<7>[ 8718.288450] l2cap_information_rsp: type 0x0002 result 0x00<br />
<7>[ 8718.288466] l2cap_conn_start: conn c41a6540<br />
<7>[ 8718.288481] hci_conn_security: conn c5361c00<br />
<7>[ 8718.288498] l2cap_build_cmd: conn c41a6540, code 0x02, ident 0x02, len 4<br />
<7>[ 8718.288516] l2cap_send_cmd: code 0x02<br />
<7>[ 8718.288529] hci_send_acl: hci0 conn c5361c00 flags 0x0<br />
<7>[ 8718.288545] hci_send_acl: hci0 nonfrag skb cd679240 len 16<br />
<7>[ 8718.288565] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.288577] hci_sched_acl: hci0<br />
<7>[ 8718.288589] hci_low_sent: conn c5361c00 quote 8<br />
<7>[ 8718.288603] hci_sched_acl: skb cd679240 len 16<br />
<7>[ 8718.288616] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.288632] hci_send_frame: hci0 type 2 len 16<br />
<7>[ 8718.288644] btusb_send_frame: hci0<br />
<7>[ 8718.288663] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.288674] hci_sched_sco: hci0<br />
<7>[ 8718.288686] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.288697] hci_sched_esco: hci0<br />
<7>[ 8718.288709] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.288821] btusb_tx_complete: hci0 urb c41a6840 status 0 count 16<br />
<7>[ 8718.293753] btusb_intr_complete: hci0 urb c706be40 status 0 count 7<br />
<7>[ 8718.293785] hci_rx_task: hci0<br />
<7>[ 8718.293796] hci_rx_task: hci0 event packet<br />
<7>[ 8718.293810] hci_num_comp_pkts_evt: hci0 num_hndl 1<br />
<7>[ 8718.293824] hci_event_packet: hci0 non-default event 0x13<br />
<7>[ 8718.293841] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.293852] hci_sched_acl: hci0<br />
<7>[ 8718.293864] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.293875] hci_sched_sco: hci0<br />
<7>[ 8718.293886] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.293898] hci_sched_esco: hci0<br />
<7>[ 8718.293909] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.299434] btusb_bulk_complete: hci0 urb c706b140 status 0 count 32<br />
<7>[ 8718.299469] hci_rx_task: hci0<br />
<7>[ 8718.299480] hci_rx_task: hci0 ACL data packet<br />
<7>[ 8718.299495] hci_acldata_packet: hci0 len 28 handle 0x2a flags 0x2<br />
<7>[ 8718.299512] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.299529] l2cap_recv_acldata: conn c41a6540 len 28 flags 0x2<br />
<7>[ 8718.299545] l2cap_recv_frame: len 24, cid 0x0001<br />
<7>[ 8718.299557] l2cap_raw_recv: conn c41a6540<br />
<7>[ 8718.299571] l2cap_sig_channel: code 0x03 len 8 id 0x02<br />
<7>[ 8718.299589] l2cap_connect_rsp: dcid 0x0040 scid 0x0040 result 0x01 status 0x02<br />
<7>[ 8718.299608] l2cap_sig_channel: code 0x03 len 8 id 0x02<br />
<7>[ 8718.299624] l2cap_connect_rsp: dcid 0x0040 scid 0x0040 result 0x00 status 0x00<br />
<7>[ 8718.299642] l2cap_build_conf_req: sk d1d52400<br />
<7>[ 8718.299659] l2cap_build_cmd: conn c41a6540, code 0x04, ident 0x03, len 4<br />
<7>[ 8718.299676] l2cap_send_cmd: code 0x04<br />
<7>[ 8718.299690] hci_send_acl: hci0 conn c5361c00 flags 0x0<br />
<7>[ 8718.299705] hci_send_acl: hci0 nonfrag skb cd679e40 len 16<br />
<7>[ 8718.299731] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.299754] hci_sched_acl: hci0<br />
<7>[ 8718.299767] hci_low_sent: conn c5361c00 quote 8<br />
<7>[ 8718.299781] hci_sched_acl: skb cd679e40 len 16<br />
<7>[ 8718.299795] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.299810] hci_send_frame: hci0 type 2 len 16<br />
<7>[ 8718.299822] btusb_send_frame: hci0<br />
<7>[ 8718.299841] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.299853] hci_sched_sco: hci0<br />
<7>[ 8718.299865] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.299876] hci_sched_esco: hci0<br />
<7>[ 8718.299888] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.300819] btusb_tx_complete: hci0 urb c41a6840 status 0 count 16<br />
<7>[ 8718.304752] btusb_intr_complete: hci0 urb c706be40 status 0 count 7<br />
<7>[ 8718.304783] hci_rx_task: hci0<br />
<7>[ 8718.304794] hci_rx_task: hci0 event packet<br />
<7>[ 8718.304808] hci_num_comp_pkts_evt: hci0 num_hndl 1<br />
<7>[ 8718.304822] hci_event_packet: hci0 non-default event 0x13<br />
<7>[ 8718.304839] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.304851] hci_sched_acl: hci0<br />
<7>[ 8718.304862] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.304874] hci_sched_sco: hci0<br />
<7>[ 8718.304885] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.304897] hci_sched_esco: hci0<br />
<7>[ 8718.304908] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.315636] btusb_bulk_complete: hci0 urb c706b0c0 status 0 count 22<br />
<7>[ 8718.315668] hci_rx_task: hci0<br />
<7>[ 8718.315680] hci_rx_task: hci0 ACL data packet<br />
<7>[ 8718.315695] hci_acldata_packet: hci0 len 18 handle 0x2a flags 0x2<br />
<7>[ 8718.315711] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.315733] l2cap_recv_acldata: conn c41a6540 len 18 flags 0x2<br />
<7>[ 8718.315759] l2cap_recv_frame: len 14, cid 0x0001<br />
<7>[ 8718.315772] l2cap_raw_recv: conn c41a6540<br />
<7>[ 8718.315786] l2cap_sig_channel: code 0x05 len 10 id 0x03<br />
<7>[ 8718.315802] l2cap_config_rsp: scid 0x0040 flags 0x00 result 0x00<br />
<7>[ 8718.416986] btusb_bulk_complete: hci0 urb c706b140 status 0 count 14<br />
<7>[ 8718.417031] hci_rx_task: hci0<br />
<7>[ 8718.417043] hci_rx_task: hci0 ACL data packet<br />
<7>[ 8718.417059] hci_acldata_packet: hci0 len 10 handle 0x2a flags 0x2<br />
<7>[ 8718.417076] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.417094] l2cap_recv_acldata: conn c41a6540 len 10 flags 0x2<br />
<7>[ 8718.417110] l2cap_recv_frame: len 6, cid 0x0001<br />
<7>[ 8718.417124] l2cap_raw_recv: conn c41a6540<br />
<7>[ 8718.417138] l2cap_sig_channel: code 0x0a len 2 id 0x01<br />
<7>[ 8718.417153] l2cap_information_req: type 0x0002<br />
<7>[ 8718.417170] l2cap_build_cmd: conn c41a6540, code 0x0b, ident 0x01, len 8<br />
<7>[ 8718.417187] l2cap_send_cmd: code 0x0b<br />
<7>[ 8718.417201] hci_send_acl: hci0 conn c5361c00 flags 0x0<br />
<7>[ 8718.417216] hci_send_acl: hci0 nonfrag skb cd679240 len 20<br />
<7>[ 8718.417237] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.417248] hci_sched_acl: hci0<br />
<7>[ 8718.417260] hci_low_sent: conn c5361c00 quote 8<br />
<7>[ 8718.417274] hci_sched_acl: skb cd679240 len 20<br />
<7>[ 8718.417288] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.417303] hci_send_frame: hci0 type 2 len 20<br />
<7>[ 8718.417315] btusb_send_frame: hci0<br />
<7>[ 8718.417336] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.417348] hci_sched_sco: hci0<br />
<7>[ 8718.417360] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.417371] hci_sched_esco: hci0<br />
<7>[ 8718.417383] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.417822] btusb_tx_complete: hci0 urb c41a6840 status 0 count 20<br />
<7>[ 8718.422756] btusb_intr_complete: hci0 urb c706be40 status 0 count 7<br />
<7>[ 8718.422790] hci_rx_task: hci0<br />
<7>[ 8718.422802] hci_rx_task: hci0 event packet<br />
<7>[ 8718.422815] hci_num_comp_pkts_evt: hci0 num_hndl 1<br />
<7>[ 8718.422830] hci_event_packet: hci0 non-default event 0x13<br />
<7>[ 8718.422848] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.422859] hci_sched_acl: hci0<br />
<7>[ 8718.422871] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.422882] hci_sched_sco: hci0<br />
<7>[ 8718.422894] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.422905] hci_sched_esco: hci0<br />
<7>[ 8718.422917] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.433285] btusb_bulk_complete: hci0 urb c706b0c0 status 0 count 20<br />
<7>[ 8718.433317] hci_rx_task: hci0<br />
<7>[ 8718.433329] hci_rx_task: hci0 ACL data packet<br />
<7>[ 8718.433344] hci_acldata_packet: hci0 len 16 handle 0x2a flags 0x2<br />
<7>[ 8718.433360] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.433378] l2cap_recv_acldata: conn c41a6540 len 16 flags 0x2<br />
<7>[ 8718.433393] l2cap_recv_frame: len 12, cid 0x0001<br />
<7>[ 8718.433406] l2cap_raw_recv: conn c41a6540<br />
<7>[ 8718.433420] l2cap_sig_channel: code 0x04 len 8 id 0x02<br />
<7>[ 8718.433435] l2cap_config_req: dcid 0x0040 flags 0x00<br />
<7>[ 8718.433451] l2cap_parse_conf_req: sk d1d52400<br />
<7>[ 8718.433466] l2cap_get_conf_opt: type 0x01 len 2 val 0x1400<br />
<7>[ 8718.433483] l2cap_add_conf_opt: type 0x01 len 2 val 0x1400<br />
<7>[ 8718.433502] l2cap_build_cmd: conn c41a6540, code 0x05, ident 0x02, len 10<br />
<7>[ 8718.433520] l2cap_send_cmd: code 0x05<br />
<7>[ 8718.433533] hci_send_acl: hci0 conn c5361c00 flags 0x0<br />
<7>[ 8718.433548] hci_send_acl: hci0 nonfrag skb cd679e40 len 22<br />
<7>[ 8718.433566] l2cap_chan_ready: sk d1d52400, parent (null)<br />
<7>[ 8718.433582] l2cap_sock_clear_timer: sock d1d52400 state 1<br />
<7>[ 8718.433609] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.433621] hci_sched_acl: hci0<br />
<7>[ 8718.433633] hci_low_sent: conn c5361c00 quote 8<br />
<7>[ 8718.433647] hci_sched_acl: skb cd679e40 len 22<br />
<7>[ 8718.433661] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.433676] hci_send_frame: hci0 type 2 len 22<br />
<7>[ 8718.433688] btusb_send_frame: hci0<br />
<7>[ 8718.433709] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.433721] hci_sched_sco: hci0<br />
<7>[ 8718.433749] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.433761] hci_sched_esco: hci0<br />
<7>[ 8718.433773] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.433826] btusb_tx_complete: hci0 urb c41a6840 status 0 count 22<br />
<7>[ 8718.434344] l2cap_sock_sendmsg: sock d2bd5240, sk d1d52400<br />
<7>[ 8718.434365] l2cap_create_basic_pdu: sk d1d52400 len 20<br />
<7>[ 8718.434391] l2cap_do_send: sk d1d52400, skb cd679e40 len 24<br />
<7>[ 8718.434408] hci_send_acl: hci0 conn c5361c00 flags 0x0<br />
<7>[ 8718.434423] hci_send_acl: hci0 nonfrag skb cd679e40 len 28<br />
<7>[ 8718.434453] hci_tx_task: hci0 acl 7 sco 8<br />
<7>[ 8718.434464] hci_sched_acl: hci0<br />
<7>[ 8718.434477] hci_low_sent: conn c5361c00 quote 7<br />
<7>[ 8718.434491] hci_sched_acl: skb cd679e40 len 28<br />
<7>[ 8718.434505] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.434521] hci_send_frame: hci0 type 2 len 28<br />
<7>[ 8718.434535] btusb_send_frame: hci0<br />
<7>[ 8718.434557] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.434569] hci_sched_sco: hci0<br />
<7>[ 8718.434580] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.434591] hci_sched_esco: hci0<br />
<7>[ 8718.434603] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.434838] btusb_tx_complete: hci0 urb c41a6840 status 0 count 28<br />
<7>[ 8718.438755] btusb_intr_complete: hci0 urb c706be40 status 0 count 7<br />
<7>[ 8718.438795] hci_rx_task: hci0<br />
<7>[ 8718.438807] hci_rx_task: hci0 event packet<br />
<7>[ 8718.438821] hci_num_comp_pkts_evt: hci0 num_hndl 1<br />
<7>[ 8718.438835] hci_event_packet: hci0 non-default event 0x13<br />
<7>[ 8718.438854] hci_tx_task: hci0 acl 7 sco 8<br />
<7>[ 8718.438865] hci_sched_acl: hci0<br />
<7>[ 8718.438877] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.438888] hci_sched_sco: hci0<br />
<7>[ 8718.438900] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.438911] hci_sched_esco: hci0<br />
<7>[ 8718.438923] hci_low_sent: conn (null) quote 0<br />
<4>[ 8718.439126] adb_write<br />
<4>[ 8718.439191] adb_write<br />
<7>[ 8718.440815] btusb_intr_complete: hci0 urb c706be40 status 0 count 7<br />
<7>[ 8718.440852] hci_rx_task: hci0<br />
<7>[ 8718.440864] hci_rx_task: hci0 event packet<br />
<7>[ 8718.440878] hci_num_comp_pkts_evt: hci0 num_hndl 1<br />
<7>[ 8718.440892] hci_event_packet: hci0 non-default event 0x13<br />
<7>[ 8718.440909] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.440920] hci_sched_acl: hci0<br />
<7>[ 8718.440932] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.440944] hci_sched_sco: hci0<br />
<7>[ 8718.440955] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.440966] hci_sched_esco: hci0<br />
<7>[ 8718.440978] hci_low_sent: conn (null) quote 0<br />
<4>[ 8718.441285] adb_read<br />
<7>[ 8718.453688] btusb_bulk_complete: hci0 urb c706b140 status 0 count 516<br />
<7>[ 8718.453742] hci_rx_task: hci0<br />
<7>[ 8718.453754] hci_rx_task: hci0 ACL data packet<br />
<7>[ 8718.453770] hci_acldata_packet: hci0 len 512 handle 0x2a flags 0x2<br />
<7>[ 8718.453787] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.453804] l2cap_recv_acldata: conn c41a6540 len 512 flags 0x2<br />
<7>[ 8718.453820] l2cap_recv_acldata: Start: total len 676, frag len 512<br />
<7>[ 8718.454233] btusb_bulk_complete: hci0 urb c706b0c0 status 0 count 168<br />
<7>[ 8718.454267] hci_rx_task: hci0<br />
<7>[ 8718.454279] hci_rx_task: hci0 ACL data packet<br />
<7>[ 8718.454293] hci_acldata_packet: hci0 len 164 handle 0x2a flags 0x1<br />
<7>[ 8718.454310] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.454326] l2cap_recv_acldata: conn c41a6540 len 164 flags 0x1<br />
<7>[ 8718.454342] l2cap_recv_acldata: Cont: frag len 164 (expecting 164)<br />
<7>[ 8718.454360] l2cap_recv_frame: len 672, cid 0x0040<br />
<7>[ 8718.454376] l2cap_data_channel: sk d1d52400, len 672<br />
<7>[ 8718.454499] l2cap_sock_sendmsg: sock d2bd5240, sk d1d52400<br />
<7>[ 8718.454516] l2cap_create_basic_pdu: sk d1d52400 len 30<br />
<7>[ 8718.454537] l2cap_do_send: sk d1d52400, skb cd679240 len 34<br />
<7>[ 8718.454554] hci_send_acl: hci0 conn c5361c00 flags 0x0<br />
<7>[ 8718.454569] hci_send_acl: hci0 nonfrag skb cd679240 len 38<br />
<7>[ 8718.454594] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.454606] hci_sched_acl: hci0<br />
<7>[ 8718.454619] hci_low_sent: conn c5361c00 quote 8<br />
<7>[ 8718.454633] hci_sched_acl: skb cd679240 len 38<br />
<7>[ 8718.454647] hci_conn_enter_active_mode: conn c5361c00 mode 0<br />
<7>[ 8718.454663] hci_send_frame: hci0 type 2 len 38<br />
<7>[ 8718.454676] btusb_send_frame: hci0<br />
<7>[ 8718.454698] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.454710] hci_sched_sco: hci0<br />
<7>[ 8718.454722] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.454755] hci_sched_esco: hci0<br />
<7>[ 8718.454768] hci_low_sent: conn (null) quote 0<br />
<7>[ 8718.454847] btusb_tx_complete: hci0 urb c41a6840 status 0 count 38<br />
<7>[ 8718.458762] btusb_intr_complete: hci0 urb c706be40 status 0 count 7<br />
<7>[ 8718.458798] hci_rx_task: hci0<br />
<7>[ 8718.458810] hci_rx_task: hci0 event packet<br />
<7>[ 8718.458824] hci_num_comp_pkts_evt: hci0 num_hndl 1<br />
<7>[ 8718.458838] hci_event_packet: hci0 non-default event 0x13<br />
<7>[ 8718.458856] hci_tx_task: hci0 acl 8 sco 8<br />
<7>[ 8718.458867] hci_sched_acl: hci0<br />
<7>[ 8718.458879] hci_low_sent: conn (null) quote 0<br />
 

·
Registered
Joined
·
130 Posts
Discussion Starter · #20 ·
As it seems we have a kernel issue after all, I'll start a new thread for kernel bluetooth issues.
 
1 - 20 of 24 Posts
Top