Root Bluetooth Fix for Jellybean roms???

tdm · May 9, 2013

Yoinx said:
Gotcha. I'm charging a bluetooth headset right now. I wish I would've saved a logcat from the other day when I was trying to sync my phone to my laptop. The screen turned off and from the logcat it was looking like the service thought it was disconnected so it was trying to reconnect to the hardware. Got a refused connection of sorts... then starting hammering failed java errors in loops. I'll post one as soon as I can get it to do it again.

Yeah that sounds exactly like the problem that was just fixed.

Yoinx · May 9, 2013

tdm said:
Logcat please.

Here's some of one from my computer trying to configure the phone as a bluetooth device (which failed). I only include it because of the E/BTLD error releated to HCI timeout.

[HIGH]
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
W/DvcNeonEqualizer(29954): Starting fixed point NEON optimized equalizer with DVC
I/AudioService(11181): Remote Control registerMediaButtonIntent() for PendingIntent{4187e548: PendingIntentRecord{4186e4f8 com.maxmpz.audioplayer broadcastIntent}}
I/HeadsetService(29458): Audio session removed: 36
I/HeadsetService(29458): Selected configuration: bluetooth
D/dalvikvm(29954): GC_EXPLICIT freed 138K, 72% free 3101K/11056K, paused 3ms+4ms, total 38ms
W/AudioPolicyManagerBase(10964): unregisterEffect() unknown effect ID 37
W/AudioPolicyManagerBase(10964): unregisterEffect() unknown effect ID 37
W/DvcNeonEqualizer(29954): Starting fixed point NEON optimized equalizer with DVC
I/HeadsetService(29458): Audio session removed: 38
I/HeadsetService(29458): Selected configuration: bluetooth
I/AudioService(11181): Remote Control registerMediaButtonIntent() for PendingIntent{40dd9d20: PendingIntentRecord{4186e4f8 com.maxmpz.audioplayer broadcastIntent}}
D/dalvikvm(29954): GC_EXPLICIT freed 755K, 72% free 3108K/11056K, paused 10ms+12ms, total 116ms
W/bt-sdp (30675): process_service_search_attr_rsp
E/bt-btif (30675): use_rc:1
E/bt-btif (30675): bta_av_rc_opened rcb[1] shdl:1 lidx:1/0
D/EventHub(11181): No input device configuration file found for device 'AVRCP'.
I/EventHub(11181): New device: id=14, fd=171, path='/dev/input/event12', name='AVRCP', classes=0x80000001, configuration='', keyLayout='/system/usr/keylayout/AVRCP.kl', keyCharacterMap='/system/usr/keychars/Generic.kcm', builtinKeyboard=false, usingSuspendBlockIoctl=false, usingClockIoctl=false
I/InputReader(11181): Device added: id=14, name='AVRCP', sources=0x00000101
I/ActivityManager(11181): Config changes=1400 {1.0 311mcc480mnc en_US ldltr sw360dp w360dp h623dp 320dpi nrml long port appliance finger -keyb/v/h dpad/v s.18 themeResource=null}
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
W/bt-btif (30675): dm_pm_timer expires
W/bt-btif (30675): dm_pm_timer expires 0
W/bt-btif (30675): proc dm_pm_timer expires
I/AudioService(11181): AudioFocus abandonAudioFocus() from android.media.AudioManager@40f9f250com.maxmpz.audioplayer.player.PlayerService$20@40e273f8
W/AudioPolicyManagerBase(10964): unregisterEffect() unknown effect ID 39
W/AudioFlinger(10964): removeEffect_l() 0x42aca0 cannot promote chain for effect 0x40bcb0
W/AudioPolicyManagerBase(10964): unregisterEffect() unknown effect ID 39
W/PlayerService(29954): Poweramp Player Service leaves the scene
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
D/CachedBluetoothDevice(30827): onProfileStateChanged: profile HEADSET newProfileState 1
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
I/BluetoothHeadsetServiceJni(30675): connectHfpNative: sBluetoothHfpInterface: 0x5b86c760
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
W/bt-sdp (30675): process_service_search_attr_rsp
W/bt-btif (30675): dm_pm_timer expires
W/bt-btif (30675): dm_pm_timer expires 0
W/bt-btif (30675): proc dm_pm_timer expires
E/BTLD (30675): ######################################################################
E/BTLD (30675): #
E/BTLD (30675): # WARNING : BTU HCI(id=0) command timeout. opcode=0x803
E/BTLD (30675): #
E/BTLD (30675): ######################################################################
W/bt-hci (30675): HCI Cmd timeout counter 1
D/BluetoothAdapterService(1088779632)(30675): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e1c738
I/LocalBluetoothProfileManager(30827): Failed to connect HEADSET device
D/CachedBluetoothDevice(30827): onProfileStateChanged: profile HEADSET newProfileState 0
[/HIGH]

Sorry, I didnt filter the other stuff around it. Not sure why it thinks my computer's a headset... I've never connected a headset to this phone yet.

tdm · May 9, 2013

Yeah... note the dm_pm_timer_expires followed by the hci timeout. That's the bug I fixed. Well actually rmcc told me a few things to try and that's the one that worked.

Yoinx · May 9, 2013

tdm said:
Yeah... note the dm_pm_timer_expires followed by the hci timeout. That's the bug I fixed. Well actually rmcc told me a few things to try and that's the one that worked.

Cool. I just installed tonight's pac rom. I'm guessing that's got the fixes included. So I'll be testing things with that.

tdm · May 9, 2013

Yoinx said:
Cool. I just installed tonight's pac rom. I'm guessing that's got the fixes included. So I'll be testing things with that.

Fix won't be included until tomorrow's builds. I'm good but I can't get a fix from this afternoon into a build from this morning.

Yoinx · May 9, 2013

tdm said:
Fix won't be included until tomorrow's builds. I'm good but I can't get a fix from this afternoon into a build from this morning.

LoL no worries. I was confused on the build dates there. it always struck me odd that they'd have the builds in the evening for today.I thought most auto-builds were around midnight, and used the previous date (the one that they're including the changes/patches/commits from) as the the build date.

I'll grab tomorrow's build, if we aren't on the odd man out schedule, for pac and see if I can't make BT hiccup with a logcat running.

CharismaRansom · May 10, 2013

Its up. I'm so excited as I've been struggling with Bluetooth issues since moving to custom ROMs. Working in IT and this being my primary phone, having my hands tied up on phone calls is crippling. Will report back with a result. Thank you for working on this and everything g else TDM. With success I will be showing my appreciation through donations.

CharismaRansom · May 10, 2013

This certainly made Bluetooth usable again, if not totally fixed its at least recovering.

I used the native or integrated CM updated and had very unusual system responsiveness and hanging issues initially, that have seemed to resolve themselves, perhaps coincidentally, since my initial response of booting into ROM Manager, clearing Dalvik cache and rebooting. This was also not from a clean wipe, so who knows.

Thanks again for your work, and whoever was tipping in this direction with BlueSleep (Yoinx or Haynes maybe, in the CM Nightlies thread). Ill follow through when I get to my desk.

Yoinx · May 10, 2013

CharismaRansom said:
Thanks again for your work, and whoever was tipping in this direction with BlueSleep (Yoinx or Haynes maybe, in the CM Nightlies thread). Ill follow through when I get to my desk.

Wasn't me. Thanks for the shoutout though. Lol.

Yoinx · May 10, 2013

Alright, so I was able to connect my headset. Make a call with it. Went to go toggle bluetooth back and forth to see if I couldn't break it. The first time I went to toggle bluetooth off it hung on "Turning Bluetooth off..." so I couldn't turn it back on.

The only thing that looked useful on my logcat I had rolling during this was: (edited to remove worthless dalvikvm, icing and other lines)

This is from today's build (5/10)

[high]
D/BluetoothManagerService(20751): disable(): mBluetooth = android.bluetooth.IBluetooth$Stub$Proxy@413c6000 mBinding = false
D/ActivityThread(30345): Loading provider com.android.gmail.ui: com.google.android.gm.provider.UiProvider
D/SettingsProvider(20751): User 0 external modification to /data/data/com.android.providers.settings/databases/settings.db; event=2
D/SettingsProvider(20751): User 0 updating our caches for /data/data/com.android.providers.settings/databases/settings.db
D/BluetoothManagerService(20751): Message: 2
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
D/BluetoothManagerService(20751): Sending off request.
D/BluetoothAdapterService(21406): Broadcasting updateAdapterState() to 1 receivers.
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
D/BluetoothManagerService(20751): Message: 60
D/BluetoothManagerService(20751): MESSAGE_BLUETOOTH_STATE_CHANGE: prevState = 12, newState=13
D/BluetoothManagerService(20751): Bluetooth State Change Intent: 12 -> 13
I/BtOppRfcommListener(21406): stopping Accept Thread
E/BtOppRfcommListener(21406): Error accept connection java.io.IOException: read failed, socket might closed or timeout, read ret: -1
I/BtOppRfcommListener(21406): BluetoothSocket listen thread finished
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
W/bt-btif (21406): invalid rfc slot id: 1
W/bt-btif (21406): invalid rfc slot id: 2
W/bt-btif (21406): invalid rfc slot id: 4
W/bt-btif (21406): invalid rfc slot id: 5
W/bt-btif (21406): invalid rfc slot id: 6
W/bt-l2cap(21406): L2CAP - PSM: 0x0019 not found for deregistration
W/bt-l2cap(21406): L2CAP - PSM: 0x0017 not found for deregistration
D/btif_config_util(21406): btif_config_save_file(L153): in file name:/data/misc/bluedroid/bt_config.new
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
D/CachedBluetoothDevice(30217): Clearing all connection state for dev:520Plantronics
I/BluetoothHeadsetServiceJni(21406): connection_state_callback
E/HeadsetStateMachine(21406): terminateScoUsingVirtualVoiceCall:No present call to terminate
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
D/CachedBluetoothDevice(30217): onProfileStateChanged: profile HEADSET newProfileState 0
D/BluetoothAdapterProperties(21406): CONNECTION_STATE_CHANGE: 00:19:7F:92:12:11: 2 -> 0
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
D/CachedBluetoothDevice(30217): BT Turninig Off...Profile conn state change ignored...
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
D/BluetoothAdapterService(1088710704)(21406): getState(): mAdapterProperties: com.android.bluetooth.btservice.AdapterProperties@40e48170
I/ActivityManager(20751): Start proc com.google.android.gms for broadcast com.google.android.gms/.recovery.AccountRecoveryService$Receiver: pid=30365 uid=10051 gids={50051, 3003, 2001, 1007, 3006, 1028, 1015, 1023}
E/AudioHardwareMSM8660(20514): unknown stream
E/bt-btm (21406): btm_sec_disconnected - Clearing Pending flag
D/BluetoothManagerService(20751): Message: 20
D/BluetoothManagerService(20751): Added callback: android.bluetooth.IBluetoothManagerCallback$Stub$Proxy@40ec64c8:true
I/HeadsetService(22749): Headset=false; Bluetooth=false
D/MediaButtonBaseReceiver(30380): Initialized beeps:
D/MediaExtractor(20514): returning default extractor
I/ServiceManager(28715): Waiting for service AtCmdFwd...
I/bt_hci_bdroid(21406): bt_hc_worker_thread exiting
W/bt_userial(21406): select_read return size <=0:-1, exiting userial_read_thread
I/bt_userial_vendor(21406): device fd = 58 close
W/bt-btif (21406): ag scb idx 1 not allocated
E/bt-btif (21406): BTA AG is already disabled, ignoring ...
W/bt-l2cap(21406): L2CAP - PSM: 0x0019 not found for deregistration
W/bt-l2cap(21406): L2CAP - PSM: 0x0017 not found for deregistration
W/bt-l2cap(21406): L2CAP - PSM: 0x0019 not found for deregistration
W/bt-l2cap(21406): L2CAP - PSM: 0x0017 not found for deregistration
W/bt-l2cap(21406): L2CAP - PSM: 0x0019 not found for deregistration
W/bt-l2cap(21406): L2CAP - PSM: 0x0017 not found for deregistration
[/high]

If this isn't enough/helpful I can upload the full logcat to pastebin. I cleared it before I started playing around. But I let it run for awhile, so it made it up to about 1.5megs.

Here's a search result from my dmesg for anything with "bt". There's no extra lines searching for "blue"

[high]
Line 339: <3>[ 1714.321533] [LG_BTUI] i_vzw_bluetooth_toggle_radio : Called i_vzw_bluetooth_toggle_radio
Line 340: <3>[ 1714.335601] [LG_BTUI] i_vzw_bluetooth_power power : 0
Line 341: <3>[ 1714.380340] [LG_BTUI] i_vzw_bluetooth_toggle_radio : Called i_vzw_bluetooth_toggle_radio
Line 342: <3>[ 1714.391906] [LG_BTUI] i_vzw_bluetooth_power power : 1 send sigkill to 19929 (roid.alarmclock), adj 11, size 6189
Line 345: <3>[ 1732.110076] [LG_BTUI] i_vzw_bluetooth_toggle_radio : Called i_vzw_bluetooth_toggle_radio
Line 346: <3>[ 1732.117797] [LG_BTUI] i_vzw_bluetooth_power power : 0
Line 347: <3>[ 1732.123870] [LG_BTUI] i_vzw_bluetooth_toggle_radio : Called i_vzw_bluetooth_toggle_radio
Line 348: <3>[ 1732.131225] [LG_BTUI] i_vzw_bluetooth_power power : 1 dhd_ioctl_entry: ifidx 0, cmd 0x89f1
Line 631: <3>[ 1977.208221] [LG_BTUI] i_vzw_bluetooth_toggle_radio : Called i_vzw_bluetooth_toggle_radio
Line 632: <3>[ 1977.241882] [LG_BTUI] i_vzw_bluetooth_power power : 0
Line 633: <3>[ 1977.268127] [LG_BTUI] i_vzw_bluetooth_toggle_radio : Called i_vzw_bluetooth_toggle_radio
Line 634: <3>[ 1977.331268] [LG_BTUI] i_vzw_bluetooth_power power : 1 dhd_ioctl_entry: ifidx 0, cmd 0x89f1
Line 1028: <6>[ 2093.702575] msm_device_put:device bt_sco_bttm_rx set 1
Line 1028: <6>[ 2093.702575] msm_device_put:device bt_sco_bttm_rx set 1
Line 1030: <6>[ 2093.710845] snddev_ecodec_open: opening bt_sco_bttm_rx
Line 1030: <6>[ 2093.710845] snddev_ecodec_open: opening bt_sco_bttm_rx
Line 1034: <6>[ 2093.729553] msm_device_put:device bt_sco_bttm_tx set 1
Line 1034: <6>[ 2093.729553] msm_device_put:device bt_sco_bttm_tx set 1
Line 1070: <6>[ 2093.991058] msm_device_put:device bt_sco_bttm_rx set 1
Line 1070: <6>[ 2093.991058] msm_device_put:device bt_sco_bttm_rx set 1
Line 1174: <6>[ 2129.242614] msm_device_put:device bt_sco_bttm_rx set 0
Line 1174: <6>[ 2129.242614] msm_device_put:device bt_sco_bttm_rx set 0
Line 1176: <6>[ 2129.251770] msm_device_put:device bt_sco_bttm_tx set 0
Line 1176: <6>[ 2129.251770] msm_device_put:device bt_sco_bttm_tx set 0
Line 1179: <6>[ 2129.280975] msm_device_put:device bt_sco_bttm_rx set 0
Line 1179: <6>[ 2129.280975] msm_device_put:device bt_sco_bttm_rx set 0
Line 1180: <6>[ 2129.285308] msm_device_put:device bt_sco_bttm_tx set 0
Line 1180: <6>[ 2129.285308] msm_device_put:device bt_sco_bttm_tx set 0
Line 1188: <6>[ 2129.416534] msm_device_put:device bt_sco_bttm_rx set 1
Line 1188: <6>[ 2129.416534] msm_device_put:device bt_sco_bttm_rx set 1
Line 1190: <6>[ 2129.424804] snddev_ecodec_open: opening bt_sco_bttm_rx
Line 1190: <6>[ 2129.424804] snddev_ecodec_open: opening bt_sco_bttm_rx
Line 1200: <6>[ 2132.647827] msm_device_put:device bt_sco_bttm_rx set 0
Line 1200: <6>[ 2132.647827] msm_device_put:device bt_sco_bttm_rx set 0
Line 1203: <6>[ 2132.673156] msm_device_put:device bt_sco_bttm_tx set 0
Line 1203: <6>[ 2132.673156] msm_device_put:device bt_sco_bttm_tx set 0
Line 1439: <3>[ 2190.475219] [LG_BTUI] i_vzw_bluetooth_toggle_radio : Called i_vzw_bluetooth_toggle_radio
Line 1440: <3>[ 2190.482208] [LG_BTUI] i_vzw_bluetooth_power power : 0 send sigkill to 30380 (t.androidPlayer), adj 15, size 8640
Line 1880: <6>[ 2670.960662] msm_device_put:device bt_sco_bttm_rx set 0
Line 1880: <6>[ 2670.960662] msm_device_put:device bt_sco_bttm_rx set 0
Line 1881: <6>[ 2670.965240] msm_device_put:device bt_sco_bttm_tx set 0
Line 1881: <6>[ 2670.965240] msm_device_put:device bt_sco_bttm_tx set 0
[/high]

hayneskr · May 10, 2013

CharismaRansom said:
This certainly made Bluetooth usable again, if not totally fixed its at least recovering.

Thanks again for your work, and whoever was tipping in this direction with BlueSleep (Yoinx or Haynes maybe, in the CM Nightlies thread). Ill follow through when I get to my desk.

This was all rmcc and tdm!

tdm · May 10, 2013

Yoinx said:
Alright, so I was able to connect my headset. Make a call with it. Went to go toggle bluetooth back and forth to see if I couldn't break it. The first time I went to toggle bluetooth off it hung on "Turning Bluetooth off..." so I couldn't turn it back on

Thanks. If I can reproduce it I might take a look. But to be honest the new Bluetooth system is crap. I really hope they fix it in the next version. And that cm gets the next version running in the next couple weeks...

Yoinx · May 10, 2013

tdm said:
Thanks. If I can reproduce it I might take a look. But to be honest the new Bluetooth system is crap. I really hope they fix it in the next version. And that cm gets the next version running in the next couple weeks...

Yeah it's tough trying to get Bluetooth to do anything reproducible.

It seems like an interface could be made to hook the bluedroid calls over to bluez

Sent from my VS920 4G using Tapatalk 2

tdm · May 10, 2013

Yoinx said:
Yeah it's tough trying to get Bluetooth to do anything reproducible.

It seems like an interface could be made to hook the bluedroid calls over to bluez

Sent from my VS920 4G using Tapatalk 2

It's not hard to do. But it violates Google rules so you couldn't call it android anymore. So none of the big ROMs are going to do it.

tdm · May 10, 2013

Any further experiences with BT to report after the fix?

My nitro doesn't drop Bluetooth anymore but Pandora frequently buffers and stutters. I haven't tried voice calling yet.

Yoinx · May 10, 2013

tdm said:
Any further experiences with BT to report after the fix?

My nitro doesn't drop Bluetooth anymore but Pandora frequently buffers and stutters. I haven't tried voice calling yet.

Is your pandora playing through an ear piece? i tried to play music through poweramp with my earpiece attached, and it played through the phone speaker. Thought it should play through the earpiece... but i guess not.

tdm · May 10, 2013

Yoinx said:
Is your pandora playing through an ear piece? i tried to play music through poweramp with my earpiece attached, and it played through the phone speaker. Thought it should play through the earpiece... but i guess not.

Through a BT headset.

beddybeezy · May 10, 2013

Im using the pac rom and bt works but when i looked at my cpu usage it rarely goes into deep sleep, so i flashed the qkernel 1.3 and it fixed the deep sleep issue but it killed bluetooth. (Just thought i'd mention it)

beddybeezy · May 10, 2013

Nevermind its acting right now!

tdm · May 11, 2013

I'm noticing that my nitro isn't connecting to my car Bluetooth speaker automatically but if I tell it to connect it will. Usually on the second try. Not sure when that started as I've had the speaker off for a while.

Also back to the Pandora playback issue, sometimes the audio path disconnects and I need to toggle Bluetooth to get it back.

I really hope these issues are ironed out in the next version. I don't use Bluetooth often but it's still frustrating.

Yoinx · May 11, 2013

beddybeezy said:
Im using the pac rom and bt works but when i looked at my cpu usage it rarely goes into deep sleep, so i flashed the qkernel 1.3 and it fixed the deep sleep issue but it killed bluetooth. (Just thought i'd mention it)

Makes sense. The fix was in the kernel

Sent from my VS920 4G using Tapatalk 2

beddybeezy · May 11, 2013

Well im using cm10.1 5/10 and bt doesn't work when making a call

Yoinx · May 11, 2013

beddybeezy said:
Well im using cm10.1 5/10 and bt doesn't work when making a call

If you're able to reproduce while you have your computer handy. You should grab a logcat.

adb logcat > logcat.txt

Let it run for 10-15 seconds then you'll need to hit ctrl+c to stop it. Then post it to a site like pastebin with steps to reproduce.

On a side note, to tdm, when we're pulling logcats. Do you actually look at anything below warning levels? I only ask because if you don't we could just as easily filter a lot of the nonsense out of it. Ie: adb logcat *:W > logcat.txt

tdm · May 11, 2013

Yoinx said:
If you're able to reproduce while you have your computer handy. You should grab a logcat.

adb logcat > logcat.txt

Let it run for 10-15 seconds then you'll need to hit ctrl+c to stop it. Then post it to a site like pastebin with steps to reproduce.

On a side note, to tdm, when we're pulling logcats. Do you actually look at anything below warning levels? I only ask because if you don't we could just as easily filter a lot of the nonsense out of it. Ie: adb logcat *:W > logcat.txt

No just the default is good.

beddybeezy · May 11, 2013

Well i started doing the logcat but once i did the problem seems to have been corrected

Root Bluetooth Fix for Jellybean roms???

Android Expert

Android Expert

Android Expert

Android Expert

Android Expert

Android Expert

Lurker

Lurker

Android Expert

Android Expert

Member

Android Expert

Android Expert

Android Expert

Android Expert

Android Expert

Android Expert

Member

Member

Android Expert

Android Expert

Member

Android Expert

Android Expert

Member