Stereo A2DP bluetooth audio not working

TenchiMasaki commented 12 years ago

When I try to play something with for instance vplayer the audio is not redirected to bluetooth, it still plays back on internal speakers. This is using the JB-ROM aokp beta 1.0.

Borkata commented 12 years ago

Unfortunately I don't have A2DP device to test with. Can you please download Lumberjack from market and take some logs from logcat and dmesg, before and after connecting.

TenchiMasaki commented 12 years ago

Note these are done from JB-ROM CM10 beta 2 which still has the problem.

Here are some snippets from dmesg:

<6>[ 0.709329] Bluetooth: Core ver 2.16 <6>[ 0.712913] NET: Registered protocol family 31 <6>[ 0.718478] Bluetooth: HCI device and connection manager initialized <6>[ 0.722482] Bluetooth: HCI socket layer initialized <6>[ 0.726719] Bluetooth: L2CAP socket layer initialized <6>[ 0.730791] Bluetooth: SCO socket layer initialized <6>[ 4.110898] Bluetooth: HCI UART driver ver 2.2 <6>[ 4.114968] Bluetooth: HCI H4 protocol initialized <6>[ 4.118820] Bluetooth: HCILL protocol initialized <6>[ 4.123045] Bluetooth: BlueSleep Mode Driver Ver 1.1 <6>[ 4.955900] Bluetooth: RFCOMM TTY layer initialized <6>[ 4.960192] Bluetooth: RFCOMM socket layer initialized <6>[ 4.963144] Bluetooth: RFCOMM ver 1.11 <6>[ 4.967669] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 <6>[ 4.972750] Bluetooth: HIDP (Human Interface Emulation) ver 1.2 <6>[ 201.849614] acc_open <6>[ 201.849801] acc_release <6>[ 212.380932] binder: 114:236 transaction failed 29189, size 164-0 <7>[ 214.080594] wlan0: no IPv6 routers present <3>[ 225.066205] binder: release proc 2294, transaction 52213, not freed <6>[ 473.287120] input: AVRCP as /devices/virtual/input/input5 Here are snippets from logcat: 11-12 09:27:04.090 I/SystemServer( 284): Bluetooth Service 11-12 09:27:04.100 I/BluetoothProfileState( 284): Message:Entering Stable State 11-12 09:27:04.110 I/BluetoothProfileState( 284): Message:Entering Stable State 11-12 09:27:04.110 I/BluetoothProfileState( 284): Message:Entering Stable State 11-12 09:27:04.110 D/BluetoothAdapterStateMachine( 284): PowerOff process message: 5 11-12 09:27:04.110 D/BluetoothA2dpService( 284): has_special_extra_keys: com.amazon.mp3.metachanged 11-12 09:27:04.110 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.metachanged_track 11-12 09:27:04.150 D/BluetoothA2dpService( 284): com.amazon.mp3.metachanged_track: com.amazon.mp3.track 11-12 09:27:04.150 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.metachanged_artist 11-12 09:27:04.150 D/BluetoothA2dpService( 284): com.amazon.mp3.metachanged_artist: com.amazon.mp3.artist 11-12 09:27:04.150 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.metachanged_album 11-12 09:27:04.160 D/BluetoothA2dpService( 284): com.amazon.mp3.metachanged_album: com.amazon.mp3.album 11-12 09:27:04.160 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.metachanged_id 11-12 09:27:04.160 D/BluetoothA2dpService( 284): com.amazon.mp3.metachanged_id: com.amazon.mp3.id 11-12 09:27:04.160 D/BluetoothA2dpService( 284): has_special_extra_keys: com.amazon.mp3.playstatechanged 11-12 09:27:04.160 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.playstatechanged_track 11-12 09:27:04.160 D/BluetoothA2dpService( 284): com.amazon.mp3.playstatechanged_track: com.amazon.mp3.track 11-12 09:27:04.160 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.playstatechanged_artist 11-12 09:27:04.160 D/BluetoothA2dpService( 284): com.amazon.mp3.playstatechanged_artist: com.amazon.mp3.artist 11-12 09:27:04.160 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.playstatechanged_album 11-12 09:27:04.170 D/BluetoothA2dpService( 284): com.amazon.mp3.playstatechanged_album: com.amazon.mp3.album 11-12 09:27:04.170 D/BluetoothA2dpService( 284): key_name: com.amazon.mp3.playstatechanged_id 11-12 09:27:04.170 D/BluetoothA2dpService( 284): com.amazon.mp3.playstatechanged_id: com.amazon.mp3.id 11-12 09:27:06.410 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.410 I/SystemServer( 284): DropBox Service 11-12 09:27:06.410 I/SystemServer( 284): Wallpaper Service 11-12 09:27:06.420 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.430 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.440 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.450 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.460 I/wpa_supplicant( 354): rfkill: Cannot open RFKILL control device 11-12 09:27:06.460 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.480 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.490 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.500 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.510 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.520 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.freedesktop.DBus.Error.ServiceUnknown (The name org.bluez was not provided by any .service files) 11-12 09:27:06.560 I/SystemServer( 284): Audio Service 11-12 09:27:06.570 I/AudioService( 284): Remote Control registerMediaButtonIntent() for PendingIntent{41c90320: PendingIntentRecord{42042350 android broadcastIntent}} 11-12 09:27:06.600 E/BluetoothEventLoop.cpp( 284): get_adapter_path: D-Bus error: org.bluez.Error.NoSuchAdapter (No such adapter) 11-12 09:27:06.600 E/BluetoothEventLoop.cpp( 284): failure setting up Event Loop! 11-12 09:27:06.630 I/SystemServer( 284): Dock Observer 11-12 09:27:06.630 W/DockObserver( 284): This kernel does not have dock station support 11-12 09:27:06.630 I/SystemServer( 284): Wired Accessory Observer 11-12 09:27:06.630 W/WiredAccessoryObserver( 284): This kernel does not have usb audio support 11-12 09:27:06.630 W/WiredAccessoryObserver( 284): This kernel does not have samsung usb dock audio support 11-12 09:27:07.240 D/BluetoothEventLoop( 284): Property Changed: Pairable : false 11-12 09:27:07.240 D/BluetoothEventLoop( 284): Property Changed: Powered : false 11-12 09:27:07.240 D/BluetoothEventLoop( 284): Property Changed: UUIDs : 5 11-12 09:33:23.970 D/audio_hw_primary( 1385): start_output_stream: device:0, rate:48000, channels:2 11-12 09:33:23.970 D/WifiService( 1509): setWifiEnabled: true pid=3399, uid=1000 11-12 09:33:24.090 D/dalvikvm( 1509): GC_EXPLICIT freed 100K, 25% free 9587K/12615K, paused 2ms+6ms, total 73ms 11-12 09:33:24.100 D/LocalBluetoothManager( 3399): setting foreground activity to non-null context 11-12 09:33:25.480 D/BluetoothAdapterStateMachine( 1509): HotOff process message: 1 11-12 09:33:25.480 D/BluetoothAdapterStateMachine( 1509): Bluetooth state 10 -> 11 11-12 09:33:25.540 I/ActivityManager( 1509): Start proc com.android.bluetooth for broadcast com.android.bluetooth/.pbap.BluetoothPbapReceiver: pid=3417 uid=10060 gids={3003, 3002, 3001, 1015, 1028} 11-12 09:33:25.930 I/ActivityThread( 3417): Pub com.android.bluetooth.opp: com.android.bluetooth.opp.BluetoothOppProvider 11-12 09:33:25.970 I/ActivityManager( 1509): No longer want com.tmobile.thememanager (pid 3159): hidden #16 11-12 09:33:25.990 V/BluetoothMasReceiver( 3417): BluetoothMasReceiver onReceive :android.bluetooth.adapter.action.STATE_CHANGED 11-12 09:33:25.990 E/BluetoothMasReceiver( 3417): BluetoothMasReceiver onReceive :android.bluetooth.adapter.action.STATE_CHANGED 11-12 09:33:25.990 D/BluetoothMasReceiver( 3417): Bluetooth STATE CHANGED to 11 11-12 09:33:26.250 D/BluetoothEventLoop( 1509): Property Changed: Powered : true 11-12 09:33:26.250 D/BluetoothEventLoop( 1509): Property Changed: Pairable : true 11-12 09:33:26.260 D/BluetoothAdapterStateMachine( 1509): Switching process message: 54 11-12 09:33:26.270 D/BluetoothEventLoop( 1509): Property Changed: Class : 1704208 11-12 09:33:26.270 D/BluetoothEventLoop( 1509): Property Changed: Pairable : true 11-12 09:33:26.270 D/BluetoothEventLoop( 1509): Property Changed: Discoverable : false 11-12 09:33:26.270 D/BluetoothAdapterStateMachine( 1509): Switching process message: 53 11-12 09:33:26.280 D/BluetoothBondState( 1509): found 1 bonded devices 11-12 09:33:26.290 I/BluetoothDeviceProfileState( 1509): Entering ACL Connected state with: -2 11-12 09:33:26.290 D/BluetoothAdapterStateMachine( 1509): Bluetooth state 11 -> 12 11-12 09:33:26.300 D/BluetoothService( 1509): updateDeviceServiceChannelCache(BC:47:60:F4:5D:EF) 11-12 09:33:26.300 D/LocalBluetoothProfileManager( 3399): Adding local A2DP profile 11-12 09:33:26.300 D/BluetoothService( 1509): uuid(system): 0000111e-0000-1000-8000-00805f9b34fb 1 11-12 09:33:26.300 D/LocalBluetoothProfileManager( 3399): Adding local HEADSET profile 11-12 09:33:26.300 D/BluetoothService( 1509): uuid(system): 00001108-0000-1000-8000-00805f9b34fb 4 11-12 09:33:26.310 D/BluetoothA2dpService( 1509): RemoteName: HS3000 11-12 09:33:26.310 D/BluetoothA2dpService( 1509): RemoteAlias: null 11-12 09:33:26.310 D/audio_hw_primary( 1385): adev_set_parameters: kppairs: bluetooth_enabled=true 11-12 09:33:26.310 D/audio_hw_primary( 1385): adev_set_parameters: kppairs: A2dpSuspended=false 11-12 09:33:26.310 D/LocalBluetoothProfileManager( 3399): Adding local OPP profile 11-12 09:33:26.320 I/BluetoothProfileState( 1509): Message:Entering PendingCommandState State 11-12 09:33:26.320 D/BluetoothA2dpService( 1509): connectSink(BC:47:60:F4:5D:EF) 11-12 09:33:26.320 I/BluetoothProfileState( 1509): Message:Entering PendingCommandState State 11-12 09:33:26.320 I/BluetoothDeviceProfileState( 1509): Entering OutgoingHandsfree state with: 1 11-12 09:33:26.320 D/Bluetooth HSHFP( 2042): Device: BC:47:60:F4:5D:EF Headset state0 -> 1 11-12 09:33:26.330 D/BluetoothService( 1509): CONNECTION_STATE_CHANGE: BC:47:60:F4:5D:EF: 0 -> 1 11-12 09:33:26.330 D/Bluetooth HSHFP( 2042): SDP UUID: TYPE_HEADSET 11-12 09:33:26.330 I/BT HSHFP( 2042): Created RFCOMM socket fd 73. 11-12 09:33:26.330 I/BT HSHFP( 2042): async connect is in progress (Operation now in progress) 11-12 09:33:26.350 D/BluetoothAdapterStateMachine( 1509): BluetoothOn process message: 1 11-12 09:33:26.350 W/BluetoothAdapterStateMachine( 1509): BluetoothOn received: 1 11-12 09:33:26.370 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile HEADSET newProfileState 1 11-12 09:33:26.450 D/DockEventReceiver( 3399): finishStartingService: stopping service 11-12 09:33:26.490 V/BluetoothMasReceiver( 3417): BluetoothMasReceiver onReceive :android.bluetooth.adapter.action.STATE_CHANGED 11-12 09:33:26.490 E/BluetoothMasReceiver( 3417): BluetoothMasReceiver onReceive :android.bluetooth.adapter.action.STATE_CHANGED 11-12 09:33:26.490 D/BluetoothMasReceiver( 3417): Bluetooth STATE CHANGED to 12 11-12 09:33:26.510 E/BluetoothMasService( 3417): Map Service onCreate 11-12 09:33:26.510 E/BluetoothMasService( 3417): Map Service onCreate 11-12 09:33:26.510 E/BluetoothMasService( 3417): Starting MAP service 11-12 09:33:26.510 I/BtOppRfcommListener( 3417): Accept thread started on channel 12 11-12 09:33:26.510 E/BluetoothMasService( 3417): Map Service onStartCommand 11-12 09:33:26.510 E/BluetoothMasService( 3417): action: android.bluetooth.adapter.action.STATE_CHANGED 11-12 09:33:31.459 E/BT HSHFP( 2042): RFCOMM async connect() error: Host is down (112), nr = -1 11-12 09:33:31.459 I/Bluetooth HSHFP( 2042): Trying to connect to rfcomm socket again after 1 sec 11-12 09:33:32.460 I/BT HSHFP( 2042): Created RFCOMM socket fd 73. 11-12 09:33:32.460 I/BT HSHFP( 2042): async connect is in progress (Operation now in progress) 11-12 09:33:32.520 E/BluetoothMasService( 3417): Handler(): got msg=1 11-12 09:33:32.520 E/BluetoothMasService( 3417): Map Service startRfcommSocketListener 11-12 09:33:32.520 E/BluetoothMasService( 3417): Map Service initSocket 11-12 09:33:32.520 E/BluetoothMasService( 3417): Succeed to create listening socket on channel 16 11-12 09:33:37.590 E/BT HSHFP( 2042): RFCOMM async connect() error: Host is down (112), nr = -1 11-12 09:33:37.590 D/Bluetooth HSHFP( 2042): RFCOMM connection attempt took 11255 ms 11-12 09:33:37.590 W/Bluetooth HSHFP( 2042): headset.waitForAsyncConnect() error: -112 11-12 09:33:37.590 D/Bluetooth HSHFP( 2042): Rfcomm error 11-12 09:33:37.590 D/Bluetooth HSHFP( 2042): Device: BC:47:60:F4:5D:EF Headset state1 -> 0 11-12 09:33:37.590 D/BluetoothAdapterStateMachine( 1509): BluetoothOn process message: 52 11-12 09:33:37.590 D/BluetoothService( 1509): CONNECTION_STATE_CHANGE: BC:47:60:F4:5D:EF: 1 -> 0 11-12 09:33:37.610 I/BluetoothProfileState( 1509): Message:Entering Stable State 11-12 09:33:37.610 I/BluetoothDeviceProfileState( 1509): Entering ACL Connected state with: 102 11-12 09:33:37.610 I/BluetoothDeviceProfileState( 1509): Entering OutgoingA2dp state with: 3 11-12 09:33:37.610 I/LocalBluetoothProfileManager( 3399): Failed to connect HEADSET device 11-12 09:33:37.610 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile HEADSET newProfileState 0 11-12 09:33:37.610 I/BluetoothDeviceProfileState( 1509): Entering ACL Connected state with: 102 11-12 09:33:37.610 D/BluetoothA2dpService( 1509): A2DP state : device: BC:47:60:F4:5D:EF State:0->1 11-12 09:33:37.610 D/BluetoothService( 1509): CONNECTION_STATE_CHANGE: BC:47:60:F4:5D:EF: 0 -> 1 11-12 09:33:37.610 D/BluetoothA2dpService( 1509): A2DP: onSinkPropertyChanged newState is: 1 mPlayingA2dpDevice: null 11-12 09:33:37.620 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile A2DP newProfileState 1 11-12 09:33:42.740 D/BluetoothA2dpService( 1509): A2DP: onSinkPropertyChanged newState is: 0 mPlayingA2dpDevice: null 11-12 09:33:42.740 D/BluetoothA2dpService( 1509): A2DP: onSinkPropertyChanged newState is: 0 mPlayingA2dpDevice: null 11-12 09:33:42.740 D/BluetoothA2dpService( 1509): A2DP state : device: BC:47:60:F4:5D:EF State:1->0 11-12 09:33:42.740 D/BluetoothAdapterStateMachine( 1509): BluetoothOn process message: 52 11-12 09:33:42.740 D/BluetoothService( 1509): CONNECTION_STATE_CHANGE: BC:47:60:F4:5D:EF: 1 -> 0 11-12 09:33:42.740 I/LocalBluetoothProfileManager( 3399): Failed to connect A2DP device 11-12 09:33:42.740 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile A2DP newProfileState 0 11-12 09:33:42.740 I/BluetoothProfileState( 1509): Message:Entering Stable State 11-12 09:33:45.010 E/BluetoothA2dpService.cpp( 1509): onConnectSinkResult: D-Bus error: org.bluez.Error.Failed (Stream setup failed) 11-12 09:34:12.530 D/BluetoothEventLoop( 1509): Device property changed: BC:47:60:F4:5D:EF property: Connected value: true 11-12 09:34:12.560 I/HeadsetService( 2375): Headset=false; Bluetooth=true 11-12 09:34:12.560 I/HeadsetService( 2375): Selected configuration: bluetooth 11-12 09:34:12.760 D/BluetoothA2dpService( 1509): A2DP: onSinkPropertyChanged newState is: 1 mPlayingA2dpDevice: null 11-12 09:34:12.760 D/BluetoothA2dpService( 1509): A2DP state : device: BC:47:60:F4:5D:EF State:0->1 11-12 09:34:12.760 D/BluetoothService( 1509): CONNECTION_STATE_CHANGE: BC:47:60:F4:5D:EF: 0 -> 1 11-12 09:34:12.770 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile A2DP newProfileState 1 11-12 09:34:12.770 I/BluetoothEventLoop.cpp( 1509): agent_event_filter: Received method org.bluez.Agent:Authorize 11-12 09:34:12.770 I/BluetoothEventLoop( 1509): First check pass for incoming A2DP / AVRCP connection from BC:47:60:F4:5D:EF 11-12 09:34:12.770 I/BluetoothDeviceProfileState( 1509): Entering IncomingA2dp state with: 4 11-12 09:34:12.770 I/BluetoothDeviceProfileState( 1509): handleIncomingConnection:4:true 11-12 09:34:12.770 D/BluetoothEventLoop( 1509): onAgentAuthorize(/org/bluez/358/hci0/dev_BC_47_60_F4_5D_EF, 0000110d-0000-1000-8000-00805f9b34fb) = true 11-12 09:34:12.770 D/BluetoothA2dpService( 1509): allowIncomingConnect: A2DP: BC:47:60:F4:5D:EF:true 11-12 09:34:13.040 I/BluetoothAudioGateway.cpp( 2042): Accepting HS connection. 11-12 09:34:13.040 I/BluetoothAudioGateway.cpp( 2042): Successful accept() on AG socket 69: new socket 73, address BC:47:60:F4:5D:EF, RFCOMM channel 11 11-12 09:34:13.040 I/BT Audio Gateway( 2042): connect notification! 11-12 09:34:13.040 I/BT Audio Gateway( 2042): Incoming connection from headset BC:47:60:F4:5D:EF on channel 11 11-12 09:34:13.050 I/Bluetooth HSHFP( 2042): Incoming rfcomm (headset) connection from BC:47:60:F4:5D:EFon channel 11 11-12 09:34:13.330 D/BluetoothA2dpService( 1509): A2DP: onSinkPropertyChanged newState is: 2 mPlayingA2dpDevice: null 11-12 09:34:13.330 W/AudioPolicyManagerBase( 1385): checkOutputsForDevice() could not open output for device 80 11-12 09:34:13.330 W/AudioPolicyManagerBase( 1385): checkOutputsForDevice(): No output available for device 0080 11-12 09:34:13.340 D/audio_hw_primary( 1385): adev_set_parameters: kppairs: A2dpSuspended=false 11-12 09:34:13.340 D/BluetoothA2dpService( 1509): sendMetaData /org/bluez/358/hci0/dev_BC_47_60_F4_5D_EF 11-12 09:34:13.340 D/BluetoothA2dpService( 1509): A2DP state : device: BC:47:60:F4:5D:EF State:1->2 11-12 09:34:13.340 D/BluetoothService( 1509): CONNECTION_STATE_CHANGE: BC:47:60:F4:5D:EF: 1 -> 2 11-12 09:34:13.350 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile A2DP newProfileState 2 11-12 09:34:13.350 D/BluetoothA2dpService( 1509): sendEvent /org/bluez/358/hci0/dev_BC_47_60_F4_5D_EF data 0 11-12 09:34:13.350 D/BluetoothA2dpService( 1509): A2DP: onSinkPropertyChanged newState is: 10 mPlayingA2dpDevice: null 11-12 09:34:13.350 I/BluetoothDeviceProfileState( 1509): Entering ACL Connected state with: 102 11-12 09:34:13.360 I/BluetoothDeviceProfileState( 1509): Entering IncomingHandsfree state with: 2 11-12 09:34:13.360 I/BluetoothDeviceProfileState( 1509): handleIncomingConnection:2:true 11-12 09:34:13.370 D/BluetoothA2dpService( 1509): A2DP Playing state : device: BC:47:60:F4:5D:EF State:11->10 11-12 09:34:13.370 E/BluetoothA2dpService.cpp( 1509): onStatusReply: D-Bus error: org.bluez.Error.NotConnected (Device not Connected) 11-12 09:34:13.370 D/Bluetooth HSHFP( 2042): Device: BC:47:60:F4:5D:EF Headset state0 -> 1 11-12 09:34:13.370 I/BT HSHFP( 2042): initializeNativeDataNative: ALREADY CONNECTED! 11-12 09:34:13.370 D/Bluetooth HSHFP( 2042): Rfcomm connected 11-12 09:34:13.370 D/Bluetooth HSHFP( 2042): Device: BC:47:60:F4:5D:EF Headset state1 -> 2 11-12 09:34:13.380 I/BluetoothDeviceProfileState( 1509): Entering ACL Connected state with: 102 11-12 09:34:13.380 D/Bluetooth HSHFP( 2042): Saved priority BC:47:60:F4:5D:EF = 1000 11-12 09:34:13.390 D/audio_hw_primary( 1385): adev_set_parameters: kppairs: bt_headset_name=HS3000;bt_headset_nrec=on 11-12 09:34:13.390 I/Bluetooth HeadsetBase( 2042): Error processing 11-12 09:34:13.400 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile HEADSET newProfileState 1 11-12 09:34:13.400 D/CachedBluetoothDevice( 3399): onProfileStateChanged: profile HEADSET newProfileState 2 11-12 09:34:13.420 I/Bluetooth HeadsetBase( 2042): Error processing 11-12 09:34:15.070 D/EventHub( 1509): No input device configuration file found for device 'AVRCP'. 11-12 09:34:15.070 I/EventHub( 1509): New device: id=6, fd=256, path='/dev/input/event5', name='AVRCP', classes=0x80000001, configuration='', keyLayout='/system/usr/keylayout/AVRCP.kl', keyCharacterMap='/system/usr/keychars/Generic.kcm', builtinKeyboard=false, usingSuspendBlockIoctl=false, usingClockIoctl=false 11-12 09:34:15.070 I/InputReader( 1509): Device added: id=6, name='AVRCP', sources=0x00000101 11-12 09:34:19.090 D/BluetoothA2dpService( 1509): A2DP: onSinkPropertyChanged newState is: 2 mPlayingA2dpDevice: BC:47:60:F4:5D:EF 11-12 09:34:19.090 D/BluetoothA2dpService( 1509): A2DP Playing state : device: BC:47:60:F4:5D:EF State:10->11 11-12 09:34:24.370 D/audio_hw_primary( 1385): start_output_stream: device:0, rate:48000, channels:2 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone begin 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone shader, BinaryData:0x5a0f2c18, size:1152 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone end 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone begin 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone shader, BinaryData:0x5a0f2b80, size:532 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone end 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone begin 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone shader, BinaryData:0x5a18e1cc, size:568 11-12 09:34:24.410 D/NvOsDebugPrintf( 1954): Clone end 11-12 09:34:27.540 D/audio_hw_primary( 1385): start_output_stream: device:0, rate:48000, channels:2 11-12 09:34:27.550 D/LocalBluetoothManager( 3399): setting foreground activity to null 11-12 09:34:27.650 D/su ( 3472): Found file /data/data/com.noshufou.android.su/files/stored/10137-0 11-12 09:34:27.650 D/su ( 3472): Comparing 'dmesg' to 'dmesg' 11-12 09:34:27.650 D/su ( 3473): Executing exec /system/bin/am broadcast -a com.noshufou.android.su.RESULT --es socket '' --ei caller_uid 10137 --ei allow 1 --ei version_code 18 11-12 09:34:27.910 D/dalvikvm( 3315): GC_CONCURRENT freed 1502K, 26% free 7114K/9543K, paused 2ms+12ms, total 114ms 11-12 09:34:27.910 D/dalvikvm( 3315): WAIT_FOR_CONCURRENT_GC blocked 85ms 11-12 09:34:27.910 D/dalvikvm( 3315): WAIT_FOR_CONCURRENT_GC blocked 91ms 11-12 09:34:27.950 D/AndroidRuntime( 3473): 11-12 09:34:27.950 D/AndroidRuntime( 3473): >>>>>> AndroidRuntime START com.android.internal.os.RuntimeInit <<<<<< 11-12 09:34:27.950 D/AndroidRuntime( 3473): CheckJNI is OFF 11-12 09:34:27.990 D/dalvikvm( 3473): Trying to load lib libjavacore.so 0x0 11-12 09:34:28.020 D/dalvikvm( 3473): Added shared lib libjavacore.so 0x0 11-12 09:34:28.040 D/dalvikvm( 3473): Trying to load lib libnativehelper.so 0x0 11-12 09:34:28.040 D/dalvikvm( 3473): Added shared lib libnativehelper.so 0x0 11-12 09:34:28.480 D/AndroidRuntime( 3473): Calling main entry com.android.commands.am.Am 11-12 09:34:28.490 D/dalvikvm( 3315): GC_CONCURRENT freed 1034K, 20% free 8012K/9927K, paused 2ms+3ms, total 109ms 11-12 09:34:28.510 D/AndroidRuntime( 3473): Shutting down VM 11-12 09:34:28.520 D/dalvikvm( 3473): GC_CONCURRENT freed 99K, 81% free 498K/2560K, paused 0ms+1ms, total 5ms 11-12 09:34:28.890 D/su ( 3472): 10137 /system/bin/mksh executing 0 dmesg using shell /system/bin/sh : sh 11-12 09:34:29.030 D/dalvikvm( 3315): null clazz in OP_INSTANCE_OF, single-stepping 11-12 09:34:49.770 I/Choreographer( 1954): Skipped 113 frames! The application may be doing too much work on its main thread. 11-12 09:35:14.440 D/audio_hw_primary( 1385): start_output_stream: device:0, rate:48000, channels:2 11-12 09:35:14.550 D/NvOsDebugPrintf( 3315): Clone begin 11-12 09:35:14.550 D/NvOsDebugPrintf( 3315): Clone shader, BinaryData:0x5c1364cc, size:592 11-12 09:35:14.550 D/NvOsDebugPrintf( 3315): Clone end 11-12 09:35:14.560 D/NvOsDebugPrintf( 3315): Clone begin 11-12 09:35:14.560 D/NvOsDebugPrintf( 3315): Clone shader, BinaryData:0x5c13a56c, size:444 11-12 09:35:14.560 D/NvOsDebugPrintf( 3315): Clone end 11-12 09:35:15.370 D/su ( 3496): Found file /data/data/com.noshufou.android.su/files/stored/10137-0 11-12 09:35:15.370 D/su ( 3496): Comparing 'dmesg' to 'dmesg' 11-12 09:35:15.370 D/su ( 3497): Executing exec /system/bin/am broadcast -a com.noshufou.android.su.RESULT --es socket '' --ei caller_uid 10137 --ei allow 1 --ei version_code 18 11-12 09:35:15.500 D/AndroidRuntime( 3497): 11-12 09:35:15.500 D/AndroidRuntime( 3497): >>>>>> AndroidRuntime START com.android.internal.os.RuntimeInit <<<<<< 11-12 09:35:15.500 D/AndroidRuntime( 3497): CheckJNI is OFF 11-12 09:35:15.520 D/dalvikvm( 3497): Trying to load lib libjavacore.so 0x0 11-12 09:35:15.520 D/dalvikvm( 3497): Added shared lib libjavacore.so 0x0 11-12 09:35:15.530 D/dalvikvm( 3497): Trying to load lib libnativehelper.so 0x0 11-12 09:35:15.530 D/dalvikvm( 3497): Added shared lib libnativehelper.so 0x0 11-12 09:35:15.710 D/AndroidRuntime( 3497): Calling main entry com.android.commands.am.Am 11-12 09:35:15.720 D/AndroidRuntime( 3497): Shutting down VM 11-12 09:35:15.730 D/dalvikvm( 3497): GC_CONCURRENT freed 99K, 81% free 498K/2560K, paused 0ms+0ms, total 6ms 11-12 09:35:16.290 D/su ( 3496): 10137 /system/bin/mksh executing 0 dmesg using shell /system/bin/sh : sh 11-12 09:37:05.060 D/audio_hw_primary( 1385): start_output_stream: device:0, rate:48000, channels:2 11-12 09:39:00.290 I/Choreographer( 1954): Skipped 319 frames! The application may be doing too much work on its main thread. 11-12 09:39:13.130 D/SurfaceFlinger( 114): About to give-up screen, flinger = 0x40dc1af0 11-12 09:39:13.190 D/audio_hw_primary( 1385): adev_set_parameters: kppairs: screen_state=off