Btld consuming resources after application stop?
I am writing a small Bluetooth-based serial control program to talk to a serial BT modem on a microcontroller board. It is mostly based on the Android BluetoothChat sample program.
When I run the program from Eclipse the first time, it installs and runs just fine. However, I have found that there is some issue where when I make changes to the program and re-run it, the phone will run incredibly slow. This is reported in the activity manager as btld is consuming 94% CPU resources. The only solution at that point is to remove the battery and reboot the phone. I have tried going into the activities and stopping anything related to BT, but that doesn't help.
Also, I've just tested it with the standard BluetoothChat program from Android, and it does the same thing. It is not specific to my additional code.
I also believe, after some experimentation, that the problem occurs when the application is stopped, which happens when you force stop it or when a new package is installed. It has become incredibly annoying, as every time it happens, I must restart or remove the battery - which can be a 5 minute process. Not ideal for debugging at all.
I am running this on an HTC Inspire 4G (2.2), using Eclipse (Java), etc.
My questions are:
How can I stop btld from consuming resources?
More importantly, what is causing this to happen, and is there something I should be doing differently in my code?
For more info, I have the output from the DDMS during program close and then turning off BT. It looks like the DVM has difficulty stopping the BT service. I removed a lot of the debug messages, unless they pertain to Bluetooth, etc.
07-06 19:54:10.334: INFO/ActivityManager(1290): Force stopping package com.*******.*******.controller uid=10149
07-06 19:54:10.341: ERROR/PhoneApp(1446): -- PackageChangeBroadcastReceiver action = android.intent.action.PACKAGE_RESTARTED
07-06 19:54:10.441: DEBUG/BluetoothService(1290): Tracked app 3520 died
07-06 19:54:10.441: INFO/BTL-IFS-WRAPPER(1592): rx_data: socket disconnected.
07-06 19:54:10.441: INFO/BTL-IFS(1592): detach_client: ######## Detached client subsystem (BTS) fd -1 ########
07-06 19:54:10.441: INFO/BTL-IFS(1592): detach_client: @*@*@*@*@*@*@*@*@*@*@*@*@* (BTS) - close(-1)
07-06 19:54:10.441: INFO/BTL-IFS(1592): btl_if_notify_local_event: Notify local event BTLIF_SUBSYSTEM_DETACHED
07-06 19:54:10.441: DEBUG/(1592): btlif_bts_api_ctrl_cb: btlif_bts_api_ctrl_cb : id BTLIF_SUBSYSTEM_DETACHED (4113) on hdl 25
07-06 19:54:10.441: INFO/(1592): btlif_rfc_ctrl_chan_detached: client detached ctrl handle -1
07-06 19:54:48.621: WARN/SharedBufferStack(1794): waitForCondition(LockCondition) timed out (identity=68, status=0). CPU may be pegged. trying again.
07-06 19:54:48.621: WARN/SharedBufferStack(1794): mutex_flags = 4
07-06 19:54:48.621: WARN/SharedBufferStack(1794): [ head= 0, available= 0, queued= 1 ]reallocMask=00000000, inUse= 0, identity=68, status=0
07-06 19:54:49.621: WARN/SharedBufferStack(1794): waitForCondition(LockCondition) timed out (identity=68, status=0). CPU may be pegged. trying again.
07-06 19:54:49.621: WARN/SharedBufferStack(1794): mutex_flags = 4
07-06 19:54:49.621: WARN/SharedBufferStack(1794): [ head= 0, available= 0, queued= 1 ]reallocMask=00000000, inUse= 0, identity=68, status=0
07-06 19:54:53.611: WARN/ResourceType(1794): Failure getting entry for 0x7f090014 (t=8 e=20) in package 0: 0xffffffb5
07-06 19:54:59.621: WARN/SharedBufferStack(1794): waitForCondition(LockCondition) timed out (identity=68, status=0). CPU may be pegged. trying again.
07-06 19:54:59.621: WARN/SharedBufferStack(1794): mutex_flags = 4
07-06 19:54:59.621: WARN/SharedBufferStack(1794): [ head= 1, available= 0, queued= 1 ]reallocMask=00000000, inUse= 1, identity=68, status=0
07-06 19:55:00.621: WARN/SharedBufferStack(1794): waitForCondition(LockCondition) timed out (identity=68, status=0). CPU may be pegged. trying again.
07-06 19:55:00.621: WARN/SharedBufferStack(1794): mutex_flags = 4
07-06 19:55:00.621: WARN/SharedBufferStack(1794): [ head= 1, available= 0, queued= 1 ]reallocMask=00000000, inUse= 1, identity=68, status=0
07-06 19:55:14.641: WARN/SharedBufferStack(1794): waitForCondition(LockCondition) timed out (identity=68, status=0). CPU may be pegged. trying again.
07-06 19:55:14.641: WARN/SharedBufferStack(1794): mutex_flags = 4
07-06 19:55:14.641: WARN/SharedBufferStack(1794): [ head= 1, available= 0, queued= 1 ]reallocMask=00000000, inUse= 1, identity=68, status=0
07-06 19:55:26.621: WARN/SharedBufferStack(1290): waitForCondition(ReallocateCondition) timed out (identity=71, status=0). CPU may be pegged. trying again.
07-06 19:55:26.621: WARN/SharedBufferStack(1290): mutex_flags = a0
07-06 19:55:26.621: WARN/SharedBufferStack(1290): [ head= 0, available= 0, queued= 1 ]reallocMask=00000002, inUse= 0, identity=71, status=0
07-06 19:55:27.621: WARN/SharedBufferStack(1290): waitForCondition(ReallocateCondition) timed out (identity=71, status=0). CPU may be pegged. trying again.
07-06 19:55:27.621: WARN/SharedBufferStack(1290): mutex_flags = a0
07-06 19:55:27.621: WARN/SharedBufferStack(1290): [ head= 0, available= 0, queued= 1 ]reallocMask=00000002, inUse= 0, identity=71, status=0
07-06 19:55:28.621: WARN/SharedBufferStack(1290): waitForCondition(ReallocateCondition) timed out (identity=71, status=0). CPU may be pegged. trying again.
07-06 19:55:28.621: WARN/SharedBufferStack(1290): mutex_flags = a0
07-06 19:55:28.621: WARN/SharedBufferStack(1290): [ head= 0, available= 0, queued= 1 ]reallocMask=00000002, inUse= 0, identity=71, status=0
07-06 19:55:44.631: DEBUG/BluetoothService(1290): Already release wake lock for discoverable mode
07-06 19:55:44.631: DEBUG/BluetoothService(1290): Bluetooth state 12 -> 13
07-06 19:55:44.641: DEBUG/BluetoothHandsfree(1446): audioOff(): mPendingSco: false, mScoSocket: , mA2dpState: 0, mA2dpSuspended: false
07-06 19:55:44.641: INFO/BTL_IFC(1446): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_DISCONNECT_REQ (SCO) 0 pbytes (hdl 52)
07-06 19:55:44.641: INFO/BluetoothA2dpService(1290): A2DP profile has been disconnected
07-06 19:55:44.641: INFO/BTL_IFC(1446): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_DISCONNECT_REQ (SCO) 0 pbytes (hdl 52)
07-06 19:55:45.611: INFO/BLZ_WRAPPER(1446): btl_if_close: btl_if_close (50)
07-06 19:55:45.611: DEBUG/BLZ_WRAPPER(1446): btl_if_close: [btl_if_close] : (50:50), disc_pending 0, asnc 0, selct 0, flags 0
07-06 19:55:45.611: INFO/BTL_IFC(1446): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_DISCONNECT_REQ (AG) 2 pbytes (hdl 49)
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: wrp_close_s_only [50] (50:50) [brcm.bt.dtun]
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: data socket closed
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wsactive_del: delete wsock 50 from active list [ad3b32b8]
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: listen socket closed
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wsactive_del: delete wsock 50 from active list [ad3b32b8]
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: wsock fully closed, return to pool
07-06 19:55:45.611: DEBUG/BLZ_WRAPPER(1446): ws_async_del: [ws_async_del] : (-1:-1), disc_pending 0, asnc 0, selct 0, flags 0
07-06 19:55:45.611: INFO/BLZ_WRAPPER(1446): btl_if_close: btl_if_close (51)
07-06 19:55:45.611: DEBUG/BLZ_WRAPPER(1446): btl_if_close: [btl_if_close] : (51:51), disc_pending 0, asnc 0, selct 0, flags 0
07-06 19:55:45.611: INFO/BTL_IFC(1446): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_DISCONNECT_REQ (AG) 2 pbytes (hdl 49)
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: wrp_close_s_only [51] (51:51) [brcm.bt.dtun]
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: data socket closed
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wsactive_del: delete wsock 51 from active list [ad3b3b18]
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: listen socket closed
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wsactive_del: delete wsock 51 from active list [ad3b3b18]
07-06 19:55:45.611: DEBUG/WifiService(1290): setWifiEnabled( mAirplaneModeOverwridden=)false
07-06 19:55:45.611: DEBUG/BTL_IFC_WRP(1446): wrp_close_s_only: wsock fully closed, return to pool
07-06 19:55:45.611: DEBUG/BLZ_WRAPPER(1446): ws_async_del: [ws_async_del] : (-1:-1), disc_pending 0, asnc 0, selct 0, flags 0
07-06 19:55:45.611: INFO/BluetoothHeadsetService(1446): Headset profile has been disconnected
07-06 19:55:45.621: VERBOSE/BluetoothDataGatewayService(1290): #### DataGateway Service Received message ####
07-06 19:55:45.621: INFO/BrcmBtServiceLoader(1290): ***Received Bluetooth UNKNOWN_STATE_CHANGE Event**** : 13
07-06 19:55:45.641: VERBOSE/BtEventReceiver(2047): #### Received Bluetooth State Change Action ####
07-06 19:55:45.641: INFO/BluetoothService(1290): Got ACTION_PROFILE_DISCONNECTED, profile = 2
07-06 19:55:46.641: INFO/BluetoothService(1290): Got ACTION_PROFILE_DISCONNECTED, profile = 1
07-06 19:55:52.611: INFO/BluetoothService(1290): Got ACTION_PROFILE_DISCONNECTED, profile = 3
07-06 19:55:53.621: INFO/bluedroid(1290): bt_disable
07-06 19:55:53.621: INFO/bluedroid(1290): bt_disable: BT_LOCK_MUTEX()
07-06 19:55:53.621: INFO/bluedroid(1290): $#$#$#$# BTON_FMOFF_handling
07-06 19:55:53.621: INFO/bluedroid(1290): $#$#$#$# BTON_FMOFF_handling : receiving BT_OFF
07-06 19:55:53.621: INFO/bluedroid(1290): $#$#$#$# Stopping bluetoothd, try 10 times before giving-up ...
07-06 19:55:53.621: INFO/DTUN_HCID4(1651): ## bluetoothd terminate (15) ##
07-06 19:55:53.621: INFO/DTUN_HCID4(1651): main loop exiting
07-06 19:55:53.621: INFO/DTUN_HCID4(1651): hcid main loop exiting
07-06 19:55:53.621: INFO/DTUN_CLNT(1651): dtun_client_stop : iface [DTUN_INTERFACE] stopping...
07-06 19:55:55.631: DEBUG/ADAPTER(1651): Removing adapter /org/bluez/1651/hci0
07-06 19:55:55.631: DEBUG/DEVICE(1651): Removing device /org/bluez/1651/hci0/dev_00_06_66_04_11_88
07-06 19:55:55.631: DEBUG/DEVICE(1651): btd_device_unref(0xf518): ref=0
07-06 19:55:55.631: DEBUG/DEVICE(1651): device_free(0xf518)
07-06 19:55:55.631: DEBUG/DEVICE(1651): Removing device /org/bluez/1651/hci0/dev_00_1F_E2_DE_87_DD
07-06 19:55:55.631: DEBUG/DEVICE(1651): btd_device_unref(0xf7e8): ref=1
07-06 19:55:55.631: DEBUG/ADAPTER(1651): btd_adapter_unref(0xf180): ref=0
07-06 19:55:55.631: DEBUG/ADAPTER(1651): adapter_free(0xf180)
07-06 19:55:55.631: DEBUG/dhcp_util(1290): dhcp_stop fail. cnt: 1
07-06 19:55:55.631: INFO/DTUN_HCID4(1651): btl_cfg_set_bluetoothd_pid : service.brcm.bt.bluetoothd_pid = 0
07-06 19:55:55.641: INFO/DTUN_HCID4(1651): btl_cfg_set_bluetoothd_pid success : service.brcm.bt.bluetoothd_pid = 0, ret = 0
07-06 19:55:56.611: INFO/bluedroid(1290): $#$#$#$#$# Stopping btld, try 10 times before giving-up ...
07-06 19:55:56.631: DEBUG/WifiStateTracker(1290): Reset connections and stopping DHCP
07-06 19:55:56.711: VERBOSE/BTL_CFG(1592): btl_cfg_get_soft_onoff_enabled : service.brcm.bt.soft_onoff = 0
07-06 19:55:56.711: VERBOSE/BTL_CFG(1592): btl_cfg_get_soft_onoff_enabled : service.brcm.bt.soft_onoff = 0
07-06 19:55:56.711: INFO/BTL-IFS(1592): BTL_IF_UnregisterSubSystem: Unregistered subsystem [FM]
07-06 19:55:57.651: VERBOSE/BluetoothEventRedirector(1794): Received android.bluetooth.adapter.action.STATE_CHANGED
07-06 19:55:57.651: INFO/BluetoothEventRedirector(1794): EXTRA_STATE = 13
07-06 19:55:57.651: DEBUG/LocalBluetoothManager(1794): sky-setBluetoothStateInt :13
07-06 19:55:57.661: INFO/BTL-IFS(1592): BTL_IF_ServerShutdown: BTL-IF Server shutting down...
07-06 19:55:59.611: DEBUG/LocalBluetoothManager(1794): sky-getBluetoothState :13
07-06 19:56:00.711: WARN/BTLD(1592): BTA got unregistered event id 6
07-06 19:56:01.611: DEBUG/ASOCKWRP(1939): asocket_abort [51,52,53]
07-06 19:56:01.611: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: s 51, how 2
07-06 19:56:01.611: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: fd (51:51), bta 0, rc 1, wflags 0x20, cflags 0x2, port 9049
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: shutdown socket
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: wake up any waiting server threads
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: fd (51:51), bta 0, rc 1, wflags 0x20, cflags 0x2, port 9049
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: event BTLIF_BTS_EVT_ABORT matched
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): btlif_wait_response: unblocked fd (51:51), bta 0, rc 1, wflags 0x20, cflags 0x2, port 9049
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_poll: set errno 125 (Operation Canceled) l.2029
07-06 19:56:01.621: DEBUG/ASOCKWRP(1939): asocket_accept:ended poll socket fd:51, ret:-1
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_write: wrote 1 bytes out of 1 on fd 53
07-06 19:56:01.621: DEBUG/ASOCKWRP(1939): asocket_destroy
07-06 19:56:01.621: DEBUG/ASOCKWRP(1939): asocket_abort [51,52,53]
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: s 51, how 2
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: fd (51:51), bta 0, rc 1, wflags 0x20, cflags 0x2, port 9049
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: shutdown socket
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: wake up any waiting server threads
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: fd (51:51), bta 0, rc 1, wflags 0x20, cflags 0x2, port 9049
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: event BTLIF_BTS_EVT_ABORT matched
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_write: wrote 1 bytes out of 1 on fd 53
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_close: s 53
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_close: std close (53)
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_close: s 52
07-06 19:56:01.621: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_close: std close (52)
07-06 19:56:01.621: INFO/BLZ20_WRAPPER(1939): blz20_wrp_close: s 51
07-06 19:56:01.631: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_close: fd (51:51), bta 0, rc 1, wflags 0x20, cflags 0x2, port 9049
07-06 19:56:01.631: INFO/BLZ20_WRAPPER(1939): __close_prot_rfcomm: fd 51
07-06 19:56:01.631: INFO/BTL_IFC(1939): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_BTS_RFC_LISTEN_CANCEL (BTS) 8 pbytes (hdl 50)
07-06 19:56:01.631: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: wrp_close_s_only [51] (51:51) [brcm.bt.dtun]
07-06 19:56:01.631: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: data socket closed
07-06 19:56:01.631: DEBUG/BTL_IFC_WRP(1939): wsactive_del: delete wsock 51 from active list [ad3f73ac]
07-06 19:56:01.631: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: listen socket closed
07-06 19:56:01.631: DEBUG/BTL_IFC_WRP(1939): wsactive_del: delete wsock 51 from active list [ad3f73ac]
07-06 19:56:01.631: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: wsock fully closed, return to pool
07-06 19:56:01.631: DEBUG/BLZ20_WRAPPER(1939): btsk_dump_list: fd (54:54), bta 1, rc 7, wflags 0x20, cflags 0x2, port 9050
07-06 19:56:01.631: DEBUG/BLZ20_WRAPPER(1939): btsk_free: success
07-06 19:56:01.761: INFO/BTL-BTAPP_AV(1592): AV disabled
07-06 19:56:02.661: WARN/BTLD(1592): BTA got unregistered event id 8
07-06 19:56:02.661: WARN/BTLD(1592): BTA got unregistered event id 12
07-06 19:56:03.641: DEBUG/ASOCKWRP(1939): asocket_abort [54,55,56]
07-06 19:56:03.651: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: s 54, how 2
07-06 19:56:03.651: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: fd (54:54), bta 1, rc 7, wflags 0x20, cflags 0x2, port 9050
07-06 19:56:03.651: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: shutdown socket
07-06 19:56:03.651: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: wake up any waiting server threads
07-06 19:56:03.651: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: fd (54:54), bta 1, rc 7, wflags 0x20, cflags 0x2, port 9050
07-06 19:56:03.651: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: event BTLIF_BTS_EVT_ABORT matched
07-06 19:56:03.651: DEBUG/BLZ20_WRAPPER(1939): btlif_wait_response: unblocked fd (54:54), bta 1, rc 7, wflags 0x20, cflags 0x2, port 9050
07-06 19:56:03.651: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_poll: set errno 125 (Operation Canceled) l.2029
07-06 19:56:03.651: DEBUG/ASOCKWRP(1939): asocket_accept:ended poll socket fd:54, ret:-1
07-06 19:56:03.651: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_write: wrote 1 bytes out of 1 on fd 56
07-06 19:56:03.661: WARN/BTLD(1592): L2CAP - PSM: 0x0019 not found for deregistration
07-06 19:56:03.661: WARN/BTLD(1592): L2CAP - PSM: 0x0017 not found for deregistration
07-06 19:56:04.611: DEBUG/ASOCKWRP(1939): asocket_destroy
07-06 19:56:04.611: DEBUG/ASOCKWRP(1939): asocket_abort [54,55,56]
07-06 19:56:04.611: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: s 54, how 2
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: fd (54:54), bta 1, rc 7, wflags 0x20, cflags 0x2, port 9050
07-06 19:56:04.611: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: shutdown socket
07-06 19:56:04.611: INFO/BLZ20_WRAPPER(1939): blz20_wrp_shutdown: wake up any waiting server threads
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: fd (54:54), bta 1, rc 7, wflags 0x20, cflags 0x2, port 9050
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): btlif_signal_event: event BTLIF_BTS_EVT_ABORT matched
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_write: wrote 1 bytes out of 1 on fd 56
07-06 19:56:04.611: INFO/BLZ20_WRAPPER(1939): blz20_wrp_close: s 56
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_close: std close (56)
07-06 19:56:04.611: INFO/BLZ20_WRAPPER(1939): blz20_wrp_close: s 55
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_close: std close (55)
07-06 19:56:04.611: INFO/BLZ20_WRAPPER(1939): blz20_wrp_close: s 54
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): blz20_wrp_close: fd (54:54), bta 1, rc 7, wflags 0x20, cflags 0x2, port 9050
07-06 19:56:04.611: INFO/BLZ20_WRAPPER(1939): __close_prot_rfcomm: fd 54
07-06 19:56:04.611: INFO/BTL_IFC(1939): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_BTS_RFC_LISTEN_CANCEL (BTS) 8 pbytes (hdl 50)
07-06 19:56:04.611: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: wrp_close_s_only [54] (54:54) [brcm.bt.dtun]
07-06 19:56:04.611: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: data socket closed
07-06 19:56:04.611: DEBUG/BTL_IFC_WRP(1939): wsactive_del: delete wsock 54 from active list [ad3f7c0c]
07-06 19:56:04.611: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: listen socket closed
07-06 19:56:04.611: DEBUG/BTL_IFC_WRP(1939): wsactive_del: delete wsock 54 from active list [ad3f7c0c]
07-06 19:56:04.611: DEBUG/BTL_IFC_WRP(1939): wrp_close_s_only: wsock fully closed, return to pool
07-06 19:56:04.611: DEBUG/BLZ20_WRAPPER(1939): btsk_free: success
07-06 19:56:04.661: WARN/BTLD(1592): L2CAP - PSM: 0x0019 not found for deregistration
07-06 19:56:04.661: WARN/B开发者_JS百科TLD(1592): L2CAP - PSM: 0x0017 not found for deregistration
07-06 19:56:04.661: WARN/BTLD(1592): L2CAP - PSM: 0x0019 not found for deregistration
07-06 19:56:04.661: WARN/BTLD(1592): L2CAP - PSM: 0x0017 not found for deregistration
07-06 19:56:16.611: ERROR/bluedroid(1290): btld stop timed out
07-06 19:56:16.611: INFO/bluedroid(1290): $#$#$#$# New state is BTOFF_FMOFF_handling
07-06 19:56:16.611: INFO/bluedroid(1290): bt_disable: BT_UNLOCK_MUTEX()
07-06 19:56:23.641: DEBUG/LocalBluetoothManager(1794): sky-getBluetoothState :13
07-06 19:57:23.611: DEBUG/BluetoothService(1290): Bluetooth state 13 -> 10
07-06 19:57:23.631: VERBOSE/BluetoothEventRedirector(1794): Received android.bluetooth.adapter.action.STATE_CHANGED
07-06 19:57:24.611: INFO/BluetoothEventRedirector(1794): EXTRA_STATE = 10
07-06 19:57:24.611: DEBUG/LocalBluetoothManager(1794): sky-setBluetoothStateInt :10
07-06 19:57:24.621: DEBUG/VoldCmdListener(1203): asec list
07-06 19:57:28.631: VERBOSE/BluetoothDataGatewayService(1290): #### DataGateway Service Received message ####
07-06 19:57:28.631: INFO/BrcmBtServiceLoader(1290): ***Received Bluetooth OFF Event****
07-06 19:57:28.631: DEBUG/BluetoothServiceManager(1290): onBluetoothDisabled()
07-06 19:57:28.631: DEBUG/BluetoothServiceManager(1290): ***stopService(): Stopping service: bluetooth_ftp***
07-06 19:57:28.631: DEBUG/com_broadcom_bt_service_ftp_FTPService.cpp(1290): disableFtpServerNative
07-06 19:57:28.631: INFO/BTL_IFC(1290): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_FTPS_DISABLE (FTPS) 0 pbytes (hdl 0)
07-06 19:57:28.631: ERROR/BTL_IFC(1290): ##### ERROR : tx_data: write failed (-1)#####
07-06 19:57:28.631: ERROR/BTL_IFC(1290): ##### ERROR : BTL_IFC_CtrlSend: [BTL_IFC CTRL] send failed#####
07-06 19:57:28.631: DEBUG/com_broadcom_bt_service_ftp_FTPService.cpp(1290): Unregister Sub system SUB_FTPS
07-06 19:57:28.631: DEBUG/BluetoothServiceManager(1290): ***stopService(): Stopping service: bluetooth_pbs***
07-06 19:57:28.631: DEBUG/com_broadcom_bt_service_pbap_PBAPService.cpp(1290): disablePbapServerNative
07-06 19:57:28.631: INFO/BTL_IFC(1290): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_PBS_DISABLE (PBS) 0 pbytes (hdl 147)
07-06 19:57:28.631: DEBUG/com_broadcom_bt_service_pbap_PBAPService.cpp(1290): Send Disable Command Successfully
07-06 19:57:28.631: DEBUG/com_broadcom_bt_service_pbap_PBAPService.cpp(1290): Unregister Sub system SUB_PBS
07-06 19:57:28.631: INFO/BluetoothPBAPService(1290): onPbapDisabled
07-06 19:57:35.641: DEBUG/BluetoothServiceManager(1290): ServiceStateChanged: bluetooth_pbs, 1
07-06 19:57:35.641: DEBUG/BluetoothServiceManager(1290): Finishing service bluetooth_pbs
A solution I found working (for a samsung galaxy mini) - that is quite unfriendly to the user, and not good "design" (but the broadcom firmware bug is not good "design" anyway) - but it's better than letting the user's phone freeze - is to turn OFF the bluetooth after we're done:
In both my onDestroy() and onBackPressed() - I call my cleanup() function that has something like this:
if(mBluetoothAdapter != null)
{
mBluetoothAdapter.disable();
}
mBluetoothAdapter = null;
note: this same phone "freeze" (on samsung galaxy using broadcom bt stack) after bt usage happens with the official android sdk's bluetooth_chat sample application too - same problem - so it's obviously not a programming "design" issue.
精彩评论