Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Android Bluetooth socket freeze application

I have a strange issue with bluetooth socket. If I create socket and later close application, android device freeze with very hight CPU load.

Here my sample code:

  // open socket
  public ConnectThread(final BluetoothDevice device) {
    Log.v(ConnectThread.class.getName(), "Try to get a socket");

    try {
      this.socket = device.createRfcommSocketToServiceRecord(UUID.fromString("00001101-0000-1000-8000-00805F9B34FB"));
    } catch (IOException e) {
      Log.e(ConnectThread.class.getName(), e.getMessage());
    }

    Log.v(ConnectThread.class.getName(), "Got a socket");
  }

  // close it
  public void cancel() {
    try {
      Log.v(ConnectThread.class.getName(), "cancel");
      this.socket.close();
    } catch (IOException e) {
      Log.e(ConnectThread.class.getName(), e.getMessage());
    }
  }

Dispite that I close socket with close() method, I don't understand why Android device freeze after my app close. Please note, that it only socket created, but not connected...

EDIT:

OK, there sample code:

package com.ss.test;

import java.io.IOException;
import java.util.UUID;

import android.app.Activity;
import android.bluetooth.BluetoothAdapter;
import android.bluetooth.BluetoothDevice;
import android.bluetooth.BluetoothSocket;
import android.os.Bundle;
import android.util.Log;

public class testBump extends Activity {
  @Override
  public void onCreate(Bundle savedInstanceState) {
    super.onCreate(savedInstanceState);
    setContentView(R.layout.main);

    BluetoothDevice device = this.bluetoothAdapter.getRemoteDevice("58:B0:35:6F:8E:C7");

    Log.e(testBump.class.getName(), "Try to get a socket");

    try {
      this.socket = device.createRfcommSocketToServiceRecord(UUID.fromString("00001101-0000-1000-8000-00805F9B34FB"));
    } catch (IOException e) {
      Log.e(testBump.class.getName(), e.getMessage());
    }

    Log.e(testBump.class.getName(), "Got a socket");

    Log.e(testBump.class.getName(), "DESTROY");

    try {
      this.socket.close();
    } catch (IOException e) {
      Log.e(testBump.class.getName(), e.getMessage());
    }

    Log.e(testBump.class.getName(), "DESTROYED");

  }

  @Override
  public void onDestroy() {
    super.onDestroy();
  }

  private BluetoothAdapter bluetoothAdapter = BluetoothAdapter.getDefaultAdapter();
  private BluetoothSocket socket = null;
}

and log:

12-16 11:42:40.558: ERROR/com.ss.test.testBump(3161): Try to get a socket
12-16 11:42:40.558: DEBUG/BluetoothSocket.cpp(3161): initSocketNative
12-16 11:42:40.558: INFO/BLZ20_WRAPPER(3161): blz20_wrp_socket: fam 31, type 1, prot BTPROTO_RFCOMM
12-16 11:42:40.558: DEBUG/BLZ20_WRAPPER(3161): blz20_init: initializing...
12-16 11:42:40.558: DEBUG/BTL_IFC_WRP(3161): wsactive_init: init active list
12-16 11:42:40.562: INFO/BTL_IFC(3161): main_client_thread: Client main thread starting
12-16 11:42:40.651: DEBUG/MediaProvider(2590): mMediaScannerReceiver - intent.getAction : android.intent.action.ACTION_MEDIA_SCANNER_PROGRESS
12-16 11:42:40.769: DEBUG/MediaScanner(2590): Normal  556 done (3600msec)
12-16 11:42:40.769: DEBUG/MediaScanner(2590): Sync..
12-16 11:42:40.851: DEBUG/MediaScanner(2590): Start Nazca /mnt/sdcard/external_sd
12-16 11:42:40.851: ERROR/MediaScanner(2590): Cannot get device path from mount info. Check SD Unmounted.
12-16 11:42:40.851: DEBUG/MediaScanner(2590): Normal Meta & DB Insert/Update Start
12-16 11:42:40.851: DEBUG/MediaScanner(2590): Normal    0 done (1msec)
12-16 11:42:40.855: DEBUG/MediaScanner(2590): postscan enter: directories - /mnt/sdcard
12-16 11:42:40.874: DEBUG/MediaScanner(2590): start checking FileCacheEntry
12-16 11:42:40.878: DEBUG/MediaScanner(2590): end checking FileCacheEntry
12-16 11:42:40.940: DEBUG/MediaScanner(2590): postscan return
12-16 11:42:40.940: DEBUG/MediaScanner(2590):  prescan time: 109ms
12-16 11:42:40.940: DEBUG/MediaScanner(2590):     scan time: 8327ms
12-16 11:42:40.940: DEBUG/MediaScanner(2590): postscan time: 86ms
12-16 11:42:40.940: DEBUG/MediaScanner(2590):    total time: 8522ms
12-16 11:42:40.956: DEBUG/MediaProvider(2590): mMediaScannerReceiver - intent.getAction : android.intent.action.MEDIA_SCANNER_FINISHED
12-16 11:42:40.960: ERROR/CscReceiver(2585): onReceive android.intent.action.MEDIA_SCANNER_FINISHED
12-16 11:42:40.960: DEBUG/CscReceiver(2585): isCSCimage
12-16 11:42:40.960: INFO/global(2585): Default buffer size used in BufferedReader constructor. It would be better to be explicit if an 8k-char buffer is required.
12-16 11:42:40.960: DEBUG/CscParser(2585): ID_path =/system/SW_Configuration.xml
12-16 11:42:40.960: DEBUG/CscParser(2585): return ok ID path /system/SW_Configuration.xml
12-16 11:42:40.960: DEBUG/CscReceiver(2585): Media DB Scanner finished.
12-16 11:42:40.960: ERROR/CscReceiver(2585): check_9
12-16 11:42:40.972: VERBOSE/MediaProvider(2590): Resuming ThumbWorker
12-16 11:42:40.972: INFO/MediaProvider(2590): MediaScanner stopped!!!
12-16 11:42:40.983: DEBUG/MediaScannerService(2590): done scanning volume external
12-16 11:42:40.983: INFO/MediaScannerService(2590): !@endofMediascannerservice
12-16 11:42:41.034: INFO/TEST(3050): Got intent with action Intent { act=android.intent.action.MEDIA_SCANNER_FINISHED dat=file:///mnt/sdcard cmp=com.cooliris.media/com.cooliris.cache.BootReceiver (has extras) }
12-16 11:42:41.034: DEBUG/BootReceiver(3050): ACTION_MEDIA_SCANNER_FINISHED: path = /mnt/sdcard
12-16 11:42:41.034: DEBUG/BootReceiver(3050): ImageManager.hasStorage()truetrue
12-16 11:42:41.190: INFO/CacheService(3050): Refreshing cache.
12-16 11:42:41.190: ERROR/DiskCache(3050): Delete All Cache Files!!!
12-16 11:42:41.210: ERROR/MTPRx(3059): In MtpReceiverandroid.intent.action.MEDIA_SCANNER_FINISHED
12-16 11:42:41.214: WARN/MTPRx(3059): Media scanning is finished
12-16 11:42:41.214: INFO/System.out(3059): setting Media scanner status0
12-16 11:42:41.214: INFO/System.out(3059): After setting Media scanner status0
12-16 11:42:41.245: WARN/BackupManagerService(2496): dataChanged but no participant pkg='com.android.providers.settings' uid=10035
12-16 11:42:41.249: DEBUG/MediaScannerReceiver(2590): onReceive : EXTERNAL scan FINISHED.
12-16 11:42:41.261: DEBUG/MediaReceiver(3065): MEDIA SCANNER FINISHED.
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_init: success
12-16 11:42:41.562: INFO/BTL_IFC(3161): BTL_IFC_RegisterSubSystem: Register subsystem [BTS]
12-16 11:42:41.562: INFO/BTL_IFC(3161): btl_ifc_ctrl_connect: Connect control channel for subsystem [BTS]
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): wrp_sock_create: CTRL
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): wrp_alloc_new_sock: wrp_alloc_new_sock sub 1
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): wrp_sock_create: 32
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): wrp_sock_connect: wrp_sock_connect brcm.bt.dtun:9000 (32)
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): DTUN_MAKE_LOCAL_SERVER_NAME return name: brcm.bt.dtun.9000
12-16 11:42:41.562: INFO/BTL-IFS(2751): main_server_thread: [CTRL] Client connected (22)
12-16 11:42:41.562: INFO/BTL_IFC_WRP(3161): wrp_sock_connect: Connected. (32)
12-16 11:42:41.562: INFO/BTL_IFC(3161): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_REGISTER_SUBSYS_REQ (BTS) 0 pbytes (hdl 32)
12-16 11:42:41.562: INFO/BTL-IFS(2751): attach_client: multiclient index 1
12-16 11:42:41.562: INFO/BTL-IFS(2751): attach_client: ######## Attached client subsystem BTS (22) ######## 
12-16 11:42:41.562: INFO/BTL-IFS(2751): btl_if_notify_local_event: Notify local event BTLIF_SUBSYSTEM_ATTACHED
12-16 11:42:41.562: DEBUG/(2751): btlif_bts_api_ctrl_cb: btlif_bts_api_ctrl_cb : id BTLIF_SUBSYSTEM_ATTACHED (4112) on hdl 22
12-16 11:42:41.562: INFO/(2751): btlif_rfc_ctrl_chan_attached: client attached ctrl handle 22
12-16 11:42:41.562: DEBUG/BTL-IFS(2751): send_registration_rsp: send_registration_rsp [0]
12-16 11:42:41.562: INFO/BTL-IFS(2751): send_ctrl_msg: [BTL_IFS CTRL] send BTLIF_REGISTER_SUBSYS_RSP (CTRL) 2 pbytes (hdl 22)
12-16 11:42:41.562: DEBUG/BTL_IFC(3161): BTL_IFC_RegisterSubSystem: add new ctrl fd to active set
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): wrp_wsock_create: BTS
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): wrp_alloc_new_sock: wrp_alloc_new_sock sub 15
12-16 11:42:41.562: DEBUG/BTL_IFC_WRP(3161): wrp_wsock_create: 33
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): btsk_alloc_add: success
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_socket: return 33
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_setsockopt:  fd (-1:33), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_setsockopt: configure rfcomm lm mode 0x26, (master:0, auth 1, enc 1)
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_setsockopt: success
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_setsockopt:  fd (-1:33), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_setsockopt: configure rfcomm sndbuf len 71680 bytes
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_setsockopt: success
12-16 11:42:41.562: DEBUG/BluetoothSocket.cpp(3161): ...fd 33 created (RFCOMM, lm = 26)
12-16 11:42:41.562: DEBUG/BluetoothSocket.cpp(3161): initSocketFromFdNative
12-16 11:42:41.562: DEBUG/ASOCKWRP(3161): asocket_init
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_fcntl: s 33, cmd 3
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_fcntl:  fd (-1:33), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_fcntl: s 33, cmd 4
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_fcntl:  fd (-1:33), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_fcntl: transparant fcntl
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_fcntl: s 35, cmd 3
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_fcntl: wsock not found, pass through transparantly
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_fcntl: s 35, cmd 4
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_fcntl: wsock not found, pass through transparantly
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_set_asocket: success (33,34,35)
12-16 11:42:41.562: ERROR/com.ss.test.testBump(3161): Got a socket
12-16 11:42:41.562: ERROR/com.ss.test.testBump(3161): DESTROY
12-16 11:42:41.562: DEBUG/BluetoothSocket.cpp(3161): abortNative
12-16 11:42:41.562: DEBUG/ASOCKWRP(3161): asocket_abort [33,34,35]
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_shutdown: s 33, how 2
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_shutdown:  fd (-1:33), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_shutdown: shutdown socket
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_write: wrote 1 bytes out of 1 on fd 35
12-16 11:42:41.562: DEBUG/BluetoothSocket.cpp(3161): ...asocket_abort(33) complete
12-16 11:42:41.562: DEBUG/BluetoothSocket.cpp(3161): destroyNative
12-16 11:42:41.562: DEBUG/ASOCKWRP(3161): asocket_destroy
12-16 11:42:41.562: DEBUG/ASOCKWRP(3161): asocket_abort [33,34,35]
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_shutdown: s 33, how 2
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_shutdown:  fd (-1:33), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_shutdown: shutdown socket
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_write: wrote 1 bytes out of 1 on fd 35
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_close: s 35
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_close: std close (35)
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_close: s 34
12-16 11:42:41.562: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_close: std close (34)
12-16 11:42:41.562: INFO/BLZ20_WRAPPER(3161): blz20_wrp_close: s 33
12-16 11:42:41.569: DEBUG/BLZ20_WRAPPER(3161): blz20_wrp_close:  fd (-1:33), bta -1, rc 0, wflags 0x0, cflags 0x0, port 0
12-16 11:42:41.569: INFO/BLZ20_WRAPPER(3161): __close_prot_rfcomm: fd 33
12-16 11:42:41.569: DEBUG/BTL_IFC(3161): BTL_IFC_CtrlSend: BTL_IFC_CtrlSend
12-16 11:42:41.569: INFO/BTL_IFC(3161): send_ctrl_msg: [BTL_IFC CTRL] send BTLIF_BTS_RFC_CLOSE (BTS) 8 pbytes (hdl 32)
12-16 11:42:41.569: DEBUG/(2751): btlif_bts_api_ctrl_cb: btlif_bts_api_ctrl_cb : id BTLIF_BTS_RFC_CLOSE (4468) on hdl 22
12-16 11:42:41.569: DEBUG/(2751): btlif_rfc_close: scn 0, sock 33
12-16 11:42:41.569: INFO/(2751): btlif_rfc_close: channel not found scn 0, sock 33
12-16 11:42:41.569: DEBUG/BTL_IFC_WRP(3161): wrp_close_s_only: wrp_close_s_only [33] (33:-1) []
12-16 11:42:41.569: DEBUG/BTL_IFC_WRP(3161): wrp_close_s_only: data socket closed
12-16 11:42:41.569: DEBUG/BTL_IFC_WRP(3161): wsactive_del: delete wsock 33 from active list [ad3f5f70]
12-16 11:42:41.569: DEBUG/BTL_IFC_WRP(3161): wrp_close_s_only: wsock fully closed, return to pool
12-16 11:42:41.569: DEBUG/BLZ20_WRAPPER(3161): btsk_free: success
12-16 11:42:41.569: DEBUG/BluetoothSocket.cpp(3161): ...asocket_destroy(33) complete
12-16 11:42:41.569: ERROR/com.ss.test.testBump(3161): DESTROYED

As you can see from log, socket closed successfully. Now, exit from app (it'll run in background), run to Task Manager and kill app. In that moment android device will freeze with very high CPU load.

EDIT 2:

I found, that issue reproduce on Samsung GALAXY Tab device only. For example, I can't reproduce it with my HTC Desire.

like image 286
Alex Ivasyuv Avatar asked Dec 10 '10 11:12

Alex Ivasyuv


1 Answers

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;
like image 65
kasidit Avatar answered Oct 21 '22 05:10

kasidit