All of lore.kernel.org
 help / color / mirror / Atom feed
* RFCOMM disconnection problem
@ 2012-08-03 12:15 Frederic Danis
  2012-08-03 12:22 ` Frederic Danis
  0 siblings, 1 reply; 5+ messages in thread
From: Frederic Danis @ 2012-08-03 12:15 UTC (permalink / raw)
  To: linux-bluetooth

[-- Attachment #1: Type: text/plain, Size: 761 bytes --]

Hello,

When I try to disconnect Blue Stereo 200 headset (from mrhandsfree) from 
my PC, if headset was the initiator of the connection, the low level 
(ACL) is not disconnected.
The device is still visible whith "hcitool con".

This happens with BlueZ 4.98 or from git upstream, and kernel 3.4.6.
There is no disconnection problem with kernel 3.2.

I also try to revert change "Bluetooth: Fix RFCOMM session reference 
counting issue" (commit cf33e7 in linux-stable.git) from Octavian 
Purdila in kernel 3.4.6.
With this kernel I do not get disconnection problem.

You can find attached hcidump traces.

Fred

-- 
Frederic Danis                            Open Source Technology Center
frederic.danis@intel.com                              Intel Corporation



[-- Attachment #2: hcidump.txt --]
[-- Type: text/plain, Size: 66033 bytes --]

Aug  3 11:02:35 fdanis-linux kernel: [ 6342.783813] l2cap_connect_ind: hdev hci0, bdaddr 10:04:14:D1:96:1C
Aug  3 11:02:35 fdanis-linux kernel: [ 6343.145829] l2cap_connect_cfm: hcon ffff88000c006800 bdaddr 10:04:14:D1:96:1C status 0
Aug  3 11:02:35 fdanis-linux kernel: [ 6343.145840] l2cap_conn_add: hcon ffff88000c006800 conn ffff880081914a00 hchan ffff88011007f380
Aug  3 11:02:35 fdanis-linux kernel: [ 6343.145845] l2cap_conn_ready: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.604676] l2cap_security_cfm: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.604685] rfcomm_security_cfm: conn ffff88000c006800 status 0x00 encrypt 0x01
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.610998] l2cap_recv_acldata: conn ffff880081914a00 len 12 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611004] l2cap_recv_frame: len 8, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611008] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611011] l2cap_sig_channel: code 0x02 len 4 id 0x02
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611015] l2cap_connect_req: psm 0x01 scid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611026] l2cap_chan_create: sk ffff88010e7ac400 chan ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611030] l2cap_sock_init: sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611034] __l2cap_chan_add: conn ffff880081914a00, psm 0x01, dcid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611041] __l2cap_state_change: chan ffff88010e7aec00 BT_OPEN -> BT_CONNECT2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611046] l2cap_build_cmd: conn ffff880081914a00, code 0x03, ident 0x02, len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611050] l2cap_send_cmd: code 0x03
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611059] l2cap_build_cmd: conn ffff880081914a00, code 0x0a, ident 0x01, len 2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.611064] l2cap_send_cmd: code 0x0a
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617213] l2cap_recv_acldata: conn ffff880081914a00 len 12 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617218] l2cap_recv_frame: len 8, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617220] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617223] l2cap_sig_channel: code 0x0b len 4 id 0x01
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617226] l2cap_information_rsp: type 0x0002 result 0x01
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617229] l2cap_conn_start: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617233] __l2cap_state_change: chan ffff88010e7aec00 BT_CONNECT2 -> BT_CONFIG
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617236] l2cap_build_cmd: conn ffff880081914a00, code 0x03, ident 0x02, len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617239] l2cap_send_cmd: code 0x03
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617244] l2cap_build_conf_req: chan ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617247] l2cap_build_cmd: conn ffff880081914a00, code 0x04, ident 0x02, len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.617250] l2cap_send_cmd: code 0x04
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623465] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623471] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623474] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623478] l2cap_sig_channel: code 0x04 len 8 id 0x03
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623483] l2cap_config_req: dcid 0x0040 flags 0x00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623487] l2cap_parse_conf_req: chan ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623490] l2cap_get_conf_opt: type 0x01 len 2 val 0x200
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623495] l2cap_add_conf_opt: type 0x01 len 2 val 0x200
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623498] l2cap_build_cmd: conn ffff880081914a00, code 0x05, ident 0x03, len 10
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.623502] l2cap_send_cmd: code 0x05
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624796] l2cap_recv_acldata: conn ffff880081914a00 len 14 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624801] l2cap_recv_frame: len 10, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624805] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624809] l2cap_sig_channel: code 0x05 len 6 id 0x02
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624814] l2cap_config_rsp: scid 0x0040 flags 0x00 result 0x00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624819] l2cap_conf_rfc_get: chan ffff88010e7aec00, rsp ffff88000c00401a, len 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624825] __l2cap_state_change: chan ffff88010e7aec00 BT_CONFIG -> BT_CONNECTED
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624830] l2cap_chan_ready: sk ffff88010e7ac400, parent ffff880110121000
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624835] __l2cap_state_change: chan ffff88010e7aec00 BT_CONNECTED -> BT_CONNECTED
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624916] l2cap_sock_accept: sk ffff880110121000 timeo 9223372036854775807
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624920] l2cap_sock_accept: new socket ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.624921] l2cap_sock_getname: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629788] l2cap_recv_acldata: conn ffff880081914a00 len 17 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629794] l2cap_recv_frame: len 13, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629799] l2cap_data_channel: chan ffff88010e7aec00, len 13
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629843] l2cap_sock_getname: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629851] l2cap_sock_getsockopt: sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629855] l2cap_sock_getsockopt_old: sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629860] l2cap_sock_getname: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629916] l2cap_sock_sendmsg: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629920] l2cap_create_basic_pdu: chan ffff88010e7aec00 len 14
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.629925] l2cap_do_send: chan ffff88010e7aec00, skb ffff88003f90d500 len 18 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.635994] l2cap_recv_acldata: conn ffff880081914a00 len 21 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636000] l2cap_recv_frame: len 17, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636003] l2cap_data_channel: chan ffff88010e7aec00, len 17
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636051] l2cap_sock_getname: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636056] l2cap_sock_getsockopt: sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636058] l2cap_sock_getsockopt_old: sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636062] l2cap_sock_getname: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636093] l2cap_sock_sendmsg: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636097] l2cap_create_basic_pdu: chan ffff88010e7aec00 len 27
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.636102] l2cap_do_send: chan ffff88010e7aec00, skb ffff880061c71700 len 31 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670857] l2cap_recv_acldata: conn ffff880081914a00 len 12 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670863] l2cap_recv_frame: len 8, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670866] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670868] l2cap_sig_channel: code 0x06 len 4 id 0x04
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670871] l2cap_disconnect_req: scid 0x0040 dcid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670874] l2cap_build_cmd: conn ffff880081914a00, code 0x07, ident 0x04, len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670877] l2cap_send_cmd: code 0x07
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670886] l2cap_chan_del: chan ffff88010e7aec00, conn ffff880081914a00, err 104
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670892] __l2cap_state_change: chan ffff88010e7aec00 BT_CONNECTED -> BT_CLOSED
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670967] l2cap_sock_release: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670970] l2cap_sock_shutdown: sock ffff8800c1cf0500, sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670973] l2cap_sock_kill: sk ffff88010e7ac400 state BT_CLOSED
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.670976] l2cap_sock_destruct: sk ffff88010e7ac400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717006] l2cap_recv_acldata: conn ffff880081914a00 len 12 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717013] l2cap_recv_frame: len 8, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717017] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717021] l2cap_sig_channel: code 0x02 len 4 id 0x05
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717025] l2cap_connect_req: psm 0x03 scid 0x0041
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717035] l2cap_chan_create: sk ffff88010e7aec00 chan ffff88010e7a9000
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717039] l2cap_sock_init: sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717044] __l2cap_chan_add: conn ffff880081914a00, psm 0x03, dcid 0x0041
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717051] __l2cap_state_change: chan ffff88010e7a9000 BT_OPEN -> BT_CONFIG
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717056] l2cap_build_cmd: conn ffff880081914a00, code 0x03, ident 0x05, len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717060] l2cap_send_cmd: code 0x03
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717067] l2cap_build_conf_req: chan ffff88010e7a9000
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717073] l2cap_add_conf_opt: type 0x01 len 2 val 0x3f5
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717078] l2cap_build_cmd: conn ffff880081914a00, code 0x04, ident 0x03, len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.717084] l2cap_send_cmd: code 0x04
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723217] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723222] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723226] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723229] l2cap_sig_channel: code 0x04 len 8 id 0x06
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723233] l2cap_config_req: dcid 0x0040 flags 0x00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723237] l2cap_parse_conf_req: chan ffff88010e7a9000
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723241] l2cap_get_conf_opt: type 0x01 len 2 val 0x200
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723244] l2cap_add_conf_opt: type 0x01 len 2 val 0x200
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723248] l2cap_build_cmd: conn ffff880081914a00, code 0x05, ident 0x06, len 10
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.723252] l2cap_send_cmd: code 0x05
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724551] l2cap_recv_acldata: conn ffff880081914a00 len 14 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724557] l2cap_recv_frame: len 10, cid 0x0001
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724560] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724564] l2cap_sig_channel: code 0x05 len 6 id 0x03
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724569] l2cap_config_rsp: scid 0x0040 flags 0x00 result 0x00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724574] l2cap_conf_rfc_get: chan ffff88010e7a9000, rsp ffff88000c00481a, len 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724579] __l2cap_state_change: chan ffff88010e7a9000 BT_CONFIG -> BT_CONNECTED
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724585] l2cap_chan_ready: sk ffff88010e7aec00, parent ffff88010e7a8400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724589] __l2cap_state_change: chan ffff88010e7a9000 BT_CONNECTED -> BT_CONNECTED
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724595] rfcomm_l2data_ready: ffff88010e7a8400 bytes 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724616] rfcomm_accept_connection: session ffff8801101c2180
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724628] l2cap_sock_accept: sk ffff88010e7a8400 timeo 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724635] l2cap_sock_accept: new socket ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724640] rfcomm_session_add: session ffff880110b72000 sock ffff8800c7792800
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724649] rfcomm_process_rx: session ffff880110b72000 state 2 qlen 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.724654] rfcomm_process_dlcs: session ffff880110b72000 state 2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729591] l2cap_recv_acldata: conn ffff880081914a00 len 8 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729596] l2cap_recv_frame: len 4, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729599] l2cap_data_channel: chan ffff88010e7a9000, len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729603] rfcomm_l2data_ready: ffff88010e7aec00 bytes 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729637] rfcomm_process_rx: session ffff880110b72000 state 2 qlen 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729641] rfcomm_recv_sabm: session ffff880110b72000 state 2 dlci 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729643] rfcomm_send_ua: ffff880110b72000 dlci 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729646] rfcomm_send_cmd: ffff880110b72000 cmd 115
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729648] rfcomm_send_frame: session ffff880110b72000 len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729651] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729654] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729658] l2cap_do_send: chan ffff88010e7a9000, skb ffff8800c3959600 len 8 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729663] rfcomm_process_connect: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.729667] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735796] l2cap_recv_acldata: conn ffff880081914a00 len 19 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735803] l2cap_recv_frame: len 15, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735806] l2cap_data_channel: chan ffff88010e7a9000, len 15
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735811] rfcomm_l2data_ready: ffff88010e7aec00 bytes 15
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735821] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735824] rfcomm_recv_mcc: ffff880110b72000 type 0x20 cr 2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735827] rfcomm_recv_pn: session ffff880110b72000 state 1 dlci 26
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735830] rfcomm_connect_ind: session ffff880110b72000 channel 13
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735838] rfcomm_dlc_clear_state: ffff8800c3959a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735841] rfcomm_dlc_alloc: ffff8800c3959a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735844] rfcomm_sock_alloc: sk ffff88010e7ad400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735846] rfcomm_sock_init: sk ffff88010e7ad400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735857] rfcomm_dlc_link: dlc ffff8800c3959a00 session ffff880110b72000
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735859] rfcomm_session_clear_timer: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735862] rfcomm_apply_pn: dlc ffff8800c3959a00 state 2 dlci 26 mtu 400 fc 0xf0 credits 7
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735865] rfcomm_send_pn: ffff880110b72000 cr 0 dlci 26 mtu 400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735867] rfcomm_send_frame: session ffff880110b72000 len 14
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735871] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735874] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 14
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735880] l2cap_do_send: chan ffff88010e7a9000, skb ffff8800c3959c00 len 18 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.735887] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743173] l2cap_recv_acldata: conn ffff880081914a00 len 8 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743178] l2cap_recv_frame: len 4, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743182] l2cap_data_channel: chan ffff88010e7a9000, len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743186] rfcomm_l2data_ready: ffff88010e7aec00 bytes 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743200] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743207] rfcomm_recv_sabm: session ffff880110b72000 state 1 dlci 26
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743218] rfcomm_dlc_set_timer: dlc ffff8800c3959a00 state 2 timeout 6250
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.743225] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916852] l2cap_security_cfm: conn ffff880081914a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916858] l2cap_security_cfm: chan->scid 64
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916864] rfcomm_l2state_change: ffff88010e7aec00 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916872] rfcomm_security_cfm: conn ffff88000c006800 status 0x00 encrypt 0x01
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916881] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916887] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916893] rfcomm_dlc_clear_timer: dlc ffff8800c3959a00 state 2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916897] rfcomm_dlc_set_timer: dlc ffff8800c3959a00 state 2 timeout 6250
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916902] rfcomm_sk_state_change: dlc ffff8800c3959a00 state 6 err 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916914] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916920] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916945] rfcomm_sock_accept: sk ffff88010da5fc00 timeo 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916952] rfcomm_sock_accept: new socket ffff88010e7ad400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916973] rfcomm_sock_getname: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.916976] rfcomm_sock_getname: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917148] rfcomm_dlc_accept: dlc ffff8800c3959a00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917151] rfcomm_send_ua: ffff880110b72000 dlci 26
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917153] rfcomm_send_cmd: ffff880110b72000 cmd 115
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917154] rfcomm_send_frame: session ffff880110b72000 len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917157] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917160] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 4
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917164] l2cap_do_send: chan ffff88010e7a9000, skb ffff8800c3959600 len 8 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917169] rfcomm_dlc_clear_timer: dlc ffff8800c3959a00 state 6
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917171] rfcomm_sk_state_change: dlc ffff8800c3959a00 state 1 err 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917175] rfcomm_send_msc: ffff880110b72000 cr 1 v24 0x8c
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917177] rfcomm_send_frame: session ffff880110b72000 len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917179] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917181] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.917184] l2cap_do_send: chan ffff88010e7a9000, skb ffff8800c3959200 len 12 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.923967] l2cap_recv_acldata: conn ffff880081914a00 len 13 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.923973] l2cap_recv_frame: len 9, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.923977] l2cap_data_channel: chan ffff88010e7a9000, len 9
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.923982] rfcomm_l2data_ready: ffff88010e7aec00 bytes 9
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.923996] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924003] rfcomm_recv_mcc: ffff880110b72000 type 0x38 cr 2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924007] rfcomm_recv_msc: dlci 26 cr 2 v24 0x8d
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924011] rfcomm_send_msc: ffff880110b72000 cr 0 v24 0x8d
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924014] rfcomm_send_frame: session ffff880110b72000 len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924018] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924022] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 8
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924028] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90c800 len 12 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.924040] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925194] l2cap_recv_acldata: conn ffff880081914a00 len 13 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925201] l2cap_recv_frame: len 9, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925207] l2cap_data_channel: chan ffff88010e7a9000, len 9
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925215] rfcomm_l2data_ready: ffff88010e7aec00 bytes 9
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925259] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925262] rfcomm_recv_mcc: ffff880110b72000 type 0x38 cr 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925263] rfcomm_recv_msc: dlci 26 cr 0 v24 0x8d
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925266] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925268] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 7 tx_credits 7
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925270] rfcomm_send_credits: ffff880110b72000 addr 105 credits 33
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925271] rfcomm_send_frame: session ffff880110b72000 len 5
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925273] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925275] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 5
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.925278] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90ce00 len 9 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934070] l2cap_recv_acldata: conn ffff880081914a00 len 21 flags 0x2
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934077] l2cap_recv_frame: len 17, cid 0x0040
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934082] l2cap_data_channel: chan ffff88010e7a9000, len 17
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934089] rfcomm_l2data_ready: ffff88010e7aec00 bytes 17
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934108] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934116] rfcomm_recv_data: session ffff880110b72000 state 1 dlci 26 pf 16
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934132] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934139] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 39 tx_credits 15
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934198] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934201] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 14
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934206] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934209] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934211] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 6
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934213] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934216] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 39 tx_credits 15
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934219] rfcomm_send_frame: session ffff880110b72000 len 18
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934222] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934225] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 18
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934230] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90cd00 len 22 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934235] rfcomm_send_frame: session ffff880110b72000 len 10
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934238] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934240] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 10
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934243] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90d300 len 14 priority 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934249] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934251] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:36 fdanis-linux kernel: [ 6343.934254] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 39 tx_credits 13
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319264] l2cap_recv_acldata: conn ffff880081914a00 len 20 flags 0x2
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319271] l2cap_recv_frame: len 16, cid 0x0040
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319275] l2cap_data_channel: chan ffff88010e7a9000, len 16
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319281] rfcomm_l2data_ready: ffff88010e7aec00 bytes 16
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319299] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319305] rfcomm_recv_data: session ffff880110b72000 state 1 dlci 26 pf 16
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319318] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319324] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 38 tx_credits 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319398] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319405] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 132
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319415] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319419] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319424] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319427] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 6
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319434] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 38 tx_credits 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319440] rfcomm_send_frame: session ffff880110b72000 len 137
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319449] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319452] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 137
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319457] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90c400 len 141 priority 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319463] rfcomm_send_frame: session ffff880110b72000 len 10
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319465] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319467] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 10
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319470] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90c000 len 14 priority 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319477] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319479] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.319482] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 38 tx_credits 13
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710808] l2cap_recv_acldata: conn ffff880081914a00 len 19 flags 0x2
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710814] l2cap_recv_frame: len 15, cid 0x0040
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710818] l2cap_data_channel: chan ffff88010e7a9000, len 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710824] rfcomm_l2data_ready: ffff88010e7aec00 bytes 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710843] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710852] rfcomm_recv_data: session ffff880110b72000 state 1 dlci 26 pf 16
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710860] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710863] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 37 tx_credits 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710933] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710940] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 24
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710948] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710952] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710959] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710961] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 6
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710964] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 37 tx_credits 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710967] rfcomm_send_frame: session ffff880110b72000 len 28
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710970] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710974] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 28
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710979] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90d900 len 32 priority 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710986] rfcomm_send_frame: session ffff880110b72000 len 10
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710988] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710990] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 10
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.710993] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90cb00 len 14 priority 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.711000] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.711002] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6344.711004] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 37 tx_credits 13
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097302] l2cap_recv_acldata: conn ffff880081914a00 len 26 flags 0x2
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097309] l2cap_recv_frame: len 22, cid 0x0040
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097313] l2cap_data_channel: chan ffff88010e7a9000, len 22
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097319] rfcomm_l2data_ready: ffff88010e7aec00 bytes 22
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097337] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097345] rfcomm_recv_data: session ffff880110b72000 state 1 dlci 26 pf 16
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097353] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097355] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 36 tx_credits 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097422] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097429] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 6
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097439] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097444] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097448] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 36 tx_credits 15
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097456] rfcomm_send_frame: session ffff880110b72000 len 10
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097459] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097462] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 10
Aug  3 11:02:37 fdanis-linux kernel: [ 6345.097466] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90dc00 len 14 priority 0
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485057] l2cap_recv_acldata: conn ffff880081914a00 len 20 flags 0x2
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485061] l2cap_recv_frame: len 16, cid 0x0040
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485063] l2cap_data_channel: chan ffff88010e7a9000, len 16
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485067] rfcomm_l2data_ready: ffff88010e7aec00 bytes 16
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485080] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485084] rfcomm_recv_data: session ffff880110b72000 state 1 dlci 26 pf 16
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485098] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485104] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 35 tx_credits 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485170] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485177] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 6
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485191] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485193] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485196] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 35 tx_credits 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485199] rfcomm_send_frame: session ffff880110b72000 len 10
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485202] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485205] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 10
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.485210] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90c100 len 14 priority 0
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496249] l2cap_recv_acldata: conn ffff880081914a00 len 19 flags 0x2
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496253] l2cap_recv_frame: len 15, cid 0x0040
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496256] l2cap_data_channel: chan ffff88010e7a9000, len 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496260] rfcomm_l2data_ready: ffff88010e7aec00 bytes 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496303] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496306] rfcomm_recv_data: session ffff880110b72000 state 1 dlci 26 pf 16
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496312] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496315] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 34 tx_credits 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496418] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496421] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 6
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496427] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496430] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496433] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 34 tx_credits 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496436] rfcomm_send_frame: session ffff880110b72000 len 10
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496438] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496441] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 10
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.496446] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90df00 len 14 priority 0
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531182] l2cap_recv_acldata: conn ffff880081914a00 len 20 flags 0x2
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531188] l2cap_recv_frame: len 16, cid 0x0040
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531193] l2cap_data_channel: chan ffff88010e7a9000, len 16
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531199] rfcomm_l2data_ready: ffff88010e7aec00 bytes 16
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531218] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531225] rfcomm_recv_data: session ffff880110b72000 state 1 dlci 26 pf 16
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531236] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531242] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 33 tx_credits 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531379] rfcomm_sock_sendmsg: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531383] rfcomm_dlc_send: dlc ffff8800c3959a00 mtu 400 len 6
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531660] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 0
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531663] rfcomm_process_dlcs: session ffff880110b72000 state 1
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531666] rfcomm_process_tx: dlc ffff8800c3959a00 state 1 cfc 40 rx_credits 33 tx_credits 15
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531669] rfcomm_send_frame: session ffff880110b72000 len 10
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531672] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531676] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 10
Aug  3 11:02:38 fdanis-linux kernel: [ 6345.531679] l2cap_do_send: chan ffff88010e7a9000, skb ffff88003f90c700 len 14 priority 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155133] l2cap_sock_create: sock ffff88000f207480
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155143] l2cap_chan_create: sk ffff88010e7a9c00 chan ffff88010e7adc00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155147] l2cap_sock_init: sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155157] l2cap_sock_bind: sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155165] l2cap_sock_setsockopt: sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155180] l2cap_sock_connect: sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155184] l2cap_chan_connect: 5C:AC:4C:FF:0B:FE -> 10:04:14:D1:96:1C psm 0x1001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155190] __l2cap_chan_add: conn ffff880081914a00, psm 0x19, dcid 0x0000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155193] __l2cap_state_change: chan ffff88010e7adc00 BT_BOUND -> BT_CONNECT
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155198] l2cap_build_cmd: conn ffff880081914a00, code 0x02, ident 0x04, len 4
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.155200] l2cap_send_cmd: code 0x02
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184544] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184550] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184553] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184556] l2cap_sig_channel: code 0x03 len 8 id 0x04
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184559] l2cap_connect_rsp: dcid 0x0042 scid 0x0041 result 0x00 status 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184563] __l2cap_state_change: chan ffff88010e7adc00 BT_CONNECT -> BT_CONFIG
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184566] l2cap_build_conf_req: chan ffff88010e7adc00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184569] l2cap_build_cmd: conn ffff880081914a00, code 0x04, ident 0x05, len 4
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.184572] l2cap_send_cmd: code 0x04
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185794] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185800] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185803] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185806] l2cap_sig_channel: code 0x04 len 8 id 0x07
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185809] l2cap_config_req: dcid 0x0041 flags 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185812] l2cap_parse_conf_req: chan ffff88010e7adc00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185815] l2cap_get_conf_opt: type 0x01 len 2 val 0x2a0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185818] l2cap_add_conf_opt: type 0x01 len 2 val 0x2a0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185821] l2cap_build_cmd: conn ffff880081914a00, code 0x05, ident 0x07, len 10
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.185824] l2cap_send_cmd: code 0x05
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190748] l2cap_recv_acldata: conn ffff880081914a00 len 14 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190754] l2cap_recv_frame: len 10, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190757] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190760] l2cap_sig_channel: code 0x05 len 6 id 0x05
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190764] l2cap_config_rsp: scid 0x0041 flags 0x00 result 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190768] l2cap_conf_rfc_get: chan ffff88010e7adc00, rsp ffff88000c00781a, len 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190772] __l2cap_state_change: chan ffff88010e7adc00 BT_CONFIG -> BT_CONNECTED
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190775] l2cap_chan_ready: sk ffff88010e7a9c00, parent           (null)
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190779] __l2cap_state_change: chan ffff88010e7adc00 BT_CONNECTED -> BT_CONNECTED
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190833] l2cap_sock_getsockopt: sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190836] l2cap_sock_getsockopt_old: sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190840] l2cap_sock_getname: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190842] l2cap_sock_getname: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190867] l2cap_sock_create: sock ffff88000f204c80
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190872] l2cap_chan_create: sk ffff88010e7ac400 chan ffff88010e7a9400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190874] l2cap_sock_init: sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190881] l2cap_sock_bind: sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190886] l2cap_sock_setsockopt: sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190895] l2cap_sock_connect: sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190899] l2cap_chan_connect: 5C:AC:4C:FF:0B:FE -> 10:04:14:D1:96:1C psm 0x1003
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190904] __l2cap_chan_add: conn ffff880081914a00, psm 0x17, dcid 0x0000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190906] __l2cap_state_change: chan ffff88010e7a9400 BT_BOUND -> BT_CONNECT
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190910] l2cap_build_cmd: conn ffff880081914a00, code 0x02, ident 0x06, len 4
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190912] l2cap_send_cmd: code 0x02
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190932] l2cap_sock_sendmsg: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190935] l2cap_create_basic_pdu: chan ffff88010e7adc00 len 2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.190940] l2cap_do_send: chan ffff88010e7adc00, skb ffff8800969ff900 len 6 priority 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200736] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200741] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200786] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200790] l2cap_sig_channel: code 0x03 len 8 id 0x06
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200794] l2cap_connect_rsp: dcid 0x0043 scid 0x0042 result 0x00 status 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200799] __l2cap_state_change: chan ffff88010e7a9400 BT_CONNECT -> BT_CONFIG
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200803] l2cap_build_conf_req: chan ffff88010e7a9400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200807] l2cap_build_cmd: conn ffff880081914a00, code 0x04, ident 0x07, len 4
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.200811] l2cap_send_cmd: code 0x04
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203215] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203222] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203226] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203230] l2cap_sig_channel: code 0x04 len 8 id 0x08
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203235] l2cap_config_req: dcid 0x0042 flags 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203239] l2cap_parse_conf_req: chan ffff88010e7a9400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203244] l2cap_get_conf_opt: type 0x01 len 2 val 0x200
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203248] l2cap_add_conf_opt: type 0x01 len 2 val 0x200
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203253] l2cap_build_cmd: conn ffff880081914a00, code 0x05, ident 0x08, len 10
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.203257] l2cap_send_cmd: code 0x05
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.204426] l2cap_recv_acldata: conn ffff880081914a00 len 8 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.204451] l2cap_recv_frame: len 4, cid 0x0041
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.204458] l2cap_data_channel: chan ffff88010e7adc00, len 4
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.204519] l2cap_sock_sendmsg: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.204527] l2cap_create_basic_pdu: chan ffff88010e7adc00 len 3
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.204536] l2cap_do_send: chan ffff88010e7adc00, skb ffff8800969ffc00 len 7 priority 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209462] l2cap_recv_acldata: conn ffff880081914a00 len 14 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209468] l2cap_recv_frame: len 10, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209473] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209477] l2cap_sig_channel: code 0x05 len 6 id 0x07
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209482] l2cap_config_rsp: scid 0x0042 flags 0x00 result 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209488] l2cap_conf_rfc_get: chan ffff88010e7a9400, rsp ffff88000c00781a, len 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209493] __l2cap_state_change: chan ffff88010e7a9400 BT_CONFIG -> BT_CONNECTED
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209498] l2cap_chan_ready: sk ffff88010e7ac400, parent           (null)
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209503] __l2cap_state_change: chan ffff88010e7a9400 BT_CONNECTED -> BT_CONNECTED
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209556] l2cap_sock_getsockopt: sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209561] l2cap_sock_getsockopt_old: sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209568] l2cap_sock_getname: sock ffff88000f204c80, sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209572] l2cap_sock_getname: sock ffff88000f204c80, sk ffff88010e7ac400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.209685] input: 10:04:14:D1:96:1C as /devices/virtual/input/input20
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.211883] l2cap_recv_acldata: conn ffff880081914a00 len 20 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.211887] l2cap_recv_frame: len 16, cid 0x0041
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.211890] l2cap_data_channel: chan ffff88010e7adc00, len 16
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.212030] l2cap_sock_sendmsg: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.212034] l2cap_create_basic_pdu: chan ffff88010e7adc00 len 14
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.212038] l2cap_do_send: chan ffff88010e7adc00, skb ffff88003f90cd00 len 18 priority 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.218130] l2cap_recv_acldata: conn ffff880081914a00 len 6 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.218136] l2cap_recv_frame: len 2, cid 0x0041
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.218140] l2cap_data_channel: chan ffff88010e7adc00, len 2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.218228] l2cap_sock_sendmsg: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.218232] l2cap_create_basic_pdu: chan ffff88010e7adc00 len 3
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.218236] l2cap_do_send: chan ffff88010e7adc00, skb ffff88003f90d400 len 7 priority 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258108] l2cap_recv_acldata: conn ffff880081914a00 len 6 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258113] l2cap_recv_frame: len 2, cid 0x0041
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258116] l2cap_data_channel: chan ffff88010e7adc00, len 2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258201] l2cap_sock_create: sock ffff88000f206580
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258207] l2cap_chan_create: sk ffff88010d007000 chan ffff88010d005400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258209] l2cap_sock_init: sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258217] l2cap_sock_bind: sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258224] l2cap_sock_setsockopt: sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258236] l2cap_sock_connect: sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258241] l2cap_chan_connect: 5C:AC:4C:FF:0B:FE -> 10:04:14:D1:96:1C psm 0x1005
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258247] __l2cap_chan_add: conn ffff880081914a00, psm 0x19, dcid 0x0000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258250] __l2cap_state_change: chan ffff88010d005400 BT_BOUND -> BT_CONNECT
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258255] l2cap_build_cmd: conn ffff880081914a00, code 0x02, ident 0x08, len 4
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.258258] l2cap_send_cmd: code 0x02
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265505] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265512] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265515] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265519] l2cap_sig_channel: code 0x03 len 8 id 0x08
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265523] l2cap_connect_rsp: dcid 0x0044 scid 0x0043 result 0x00 status 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265528] __l2cap_state_change: chan ffff88010d005400 BT_CONNECT -> BT_CONFIG
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265532] l2cap_build_conf_req: chan ffff88010d005400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265535] l2cap_build_cmd: conn ffff880081914a00, code 0x04, ident 0x09, len 4
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.265539] l2cap_send_cmd: code 0x04
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266741] l2cap_recv_acldata: conn ffff880081914a00 len 16 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266744] l2cap_recv_frame: len 12, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266746] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266748] l2cap_sig_channel: code 0x04 len 8 id 0x09
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266751] l2cap_config_req: dcid 0x0043 flags 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266754] l2cap_parse_conf_req: chan ffff88010d005400
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266757] l2cap_get_conf_opt: type 0x01 len 2 val 0x2a0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266760] l2cap_add_conf_opt: type 0x01 len 2 val 0x2a0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266763] l2cap_build_cmd: conn ffff880081914a00, code 0x05, ident 0x09, len 10
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.266766] l2cap_send_cmd: code 0x05
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270469] l2cap_recv_acldata: conn ffff880081914a00 len 14 flags 0x2
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270476] l2cap_recv_frame: len 10, cid 0x0001
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270479] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270482] l2cap_sig_channel: code 0x05 len 6 id 0x09
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270485] l2cap_config_rsp: scid 0x0043 flags 0x00 result 0x00
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270489] l2cap_conf_rfc_get: chan ffff88010d005400, rsp ffff88000c00501a, len 0
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270492] __l2cap_state_change: chan ffff88010d005400 BT_CONFIG -> BT_CONNECTED
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270496] l2cap_chan_ready: sk ffff88010d007000, parent           (null)
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270498] __l2cap_state_change: chan ffff88010d005400 BT_CONNECTED -> BT_CONNECTED
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270555] l2cap_sock_getsockopt: sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270557] l2cap_sock_getsockopt_old: sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270561] l2cap_sock_getname: sock ffff88000f206580, sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270563] l2cap_sock_getname: sock ffff88000f206580, sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270573] l2cap_sock_setsockopt: sk ffff88010d007000
Aug  3 11:02:39 fdanis-linux kernel: [ 6347.270575] l2cap_sock_setsockopt: sk ffff88010d007000


Aug  3 11:02:51 fdanis-linux kernel: [ 6358.966869] l2cap_sock_sendmsg: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.966940] l2cap_create_basic_pdu: chan ffff88010e7adc00 len 3
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.966946] l2cap_do_send: chan ffff88010e7adc00, skb ffff8800d2acba00 len 7 priority 0
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995894] l2cap_recv_acldata: conn ffff880081914a00 len 6 flags 0x2
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995899] l2cap_recv_frame: len 2, cid 0x0041
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995902] l2cap_data_channel: chan ffff88010e7adc00, len 2
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995977] l2cap_sock_shutdown: sock ffff88000f206580, sk ffff88010d007000
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995982] l2cap_chan_close: chan ffff88010d005400 state BT_CONNECTED sk ffff88010d007000
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995988] l2cap_build_cmd: conn ffff880081914a00, code 0x06, ident 0x0a, len 4
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995993] l2cap_send_cmd: code 0x06
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.995999] __l2cap_state_change: chan ffff88010d005400 BT_CONNECTED -> BT_DISCONN
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.996006] l2cap_sock_release: sock ffff88000f206580, sk ffff88010d007000
Aug  3 11:02:51 fdanis-linux kernel: [ 6358.996009] l2cap_sock_shutdown: sock ffff88000f206580, sk ffff88010d007000
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001949] l2cap_recv_acldata: conn ffff880081914a00 len 12 flags 0x2
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001956] l2cap_recv_frame: len 8, cid 0x0001
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001961] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001966] l2cap_sig_channel: code 0x07 len 4 id 0x0a
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001971] l2cap_disconnect_rsp: dcid 0x0044 scid 0x0043
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001976] l2cap_chan_del: chan ffff88010d005400, conn ffff880081914a00, err 0
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001982] __l2cap_state_change: chan ffff88010d005400 BT_DISCONN -> BT_CLOSED
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001988] l2cap_sock_kill: sk ffff88010d007000 state BT_CLOSED
Aug  3 11:02:51 fdanis-linux kernel: [ 6359.001994] l2cap_sock_destruct: sk ffff88010d007000
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121505] l2cap_sock_release: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121512] l2cap_sock_shutdown: sock ffff88000f207480, sk ffff88010e7a9c00
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121519] l2cap_chan_close: chan ffff88010e7adc00 state BT_CONNECTED sk ffff88010e7a9c00
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121531] l2cap_build_cmd: conn ffff880081914a00, code 0x06, ident 0x0b, len 4
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121537] l2cap_send_cmd: code 0x06
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121550] __l2cap_state_change: chan ffff88010e7adc00 BT_CONNECTED -> BT_DISCONN
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121699] l2cap_sock_release: sock ffff88000f204c80, sk ffff88010e7ac400
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121702] l2cap_sock_shutdown: sock ffff88000f204c80, sk ffff88010e7ac400
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121705] l2cap_chan_close: chan ffff88010e7a9400 state BT_CONNECTED sk ffff88010e7ac400
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121710] l2cap_build_cmd: conn ffff880081914a00, code 0x06, ident 0x0c, len 4
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121712] l2cap_send_cmd: code 0x06
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.121716] __l2cap_state_change: chan ffff88010e7a9400 BT_CONNECTED -> BT_DISCONN
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151578] l2cap_recv_acldata: conn ffff880081914a00 len 12 flags 0x2
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151583] l2cap_recv_frame: len 8, cid 0x0001
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151585] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151588] l2cap_sig_channel: code 0x07 len 4 id 0x0b
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151591] l2cap_disconnect_rsp: dcid 0x0042 scid 0x0041
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151595] l2cap_chan_del: chan ffff88010e7adc00, conn ffff880081914a00, err 0
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151599] __l2cap_state_change: chan ffff88010e7adc00 BT_DISCONN -> BT_CLOSED
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151603] l2cap_sock_kill: sk ffff88010e7a9c00 state BT_CLOSED
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.151607] l2cap_sock_destruct: sk ffff88010e7a9c00
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152730] l2cap_recv_acldata: conn ffff880081914a00 len 12 flags 0x2
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152733] l2cap_recv_frame: len 8, cid 0x0001
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152735] l2cap_raw_recv: conn ffff880081914a00
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152737] l2cap_sig_channel: code 0x07 len 4 id 0x0c
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152739] l2cap_disconnect_rsp: dcid 0x0043 scid 0x0042
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152742] l2cap_chan_del: chan ffff88010e7a9400, conn ffff880081914a00, err 0
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152745] __l2cap_state_change: chan ffff88010e7a9400 BT_DISCONN -> BT_CLOSED
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152749] l2cap_sock_kill: sk ffff88010e7ac400 state BT_CLOSED
Aug  3 11:02:52 fdanis-linux kernel: [ 6360.152751] l2cap_sock_destruct: sk ffff88010e7ac400


Aug  3 11:03:12 fdanis-linux bluetoothd[1434]: Disconnected from 10:04:14:D1:96:1C, /org/bluez/1434/hci0/dev_10_04_14_D1_96_1C
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475038] rfcomm_sock_release: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475041] rfcomm_sock_shutdown: sock ffff88000f204a00, sk ffff88010e7ad400
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475044] __rfcomm_sock_close: sk ffff88010e7ad400 state 1 socket ffff88000f204a00
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475047] __rfcomm_dlc_close: dlc ffff8800c3959a00 state 1 dlci 26 err 0 session ffff880110b72000
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475050] rfcomm_send_disc: ffff880110b72000 dlci 26
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475052] rfcomm_send_cmd: ffff880110b72000 cmd 83
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475054] rfcomm_send_frame: session ffff880110b72000 len 4
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475057] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475059] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 4
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475064] l2cap_do_send: chan ffff88010e7a9000, skb ffff88000e723c00 len 8 priority 0
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475075] rfcomm_dlc_set_timer: dlc ffff8800c3959a00 state 8 timeout 5000
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475078] rfcomm_sock_kill: sk ffff88010e7ad400 state 1 refcnt 2
Aug  3 11:03:12 fdanis-linux kernel: [ 6379.475081] rfcomm_sock_destruct: sk ffff88010e7ad400 dlc ffff8800c3959a00
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574751] l2cap_recv_acldata: conn ffff880081914a00 len 8 flags 0x2
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574758] l2cap_recv_frame: len 4, cid 0x0040
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574763] l2cap_data_channel: chan ffff88010e7a9000, len 4
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574769] rfcomm_l2data_ready: ffff88010e7aec00 bytes 4
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574787] rfcomm_process_rx: session ffff880110b72000 state 1 qlen 1
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574793] rfcomm_recv_ua: session ffff880110b72000 state 1 dlci 26
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574798] __rfcomm_dlc_close: dlc ffff8800c3959a00 state 9 dlci 26 err 0 session ffff880110b72000
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574802] rfcomm_dlc_clear_timer: dlc ffff8800c3959a00 state 9
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574806] rfcomm_dlc_unlink: dlc ffff8800c3959a00 refcnt 1 session ffff880110b72000
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574810] rfcomm_dlc_free: ffff8800c3959a00
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574815] rfcomm_session_set_timer: session ffff880110b72000 state 1 timeout 500
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574819] rfcomm_send_disc: ffff880110b72000 dlci 0
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574822] rfcomm_send_cmd: ffff880110b72000 cmd 83
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574826] rfcomm_send_frame: session ffff880110b72000 len 4
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574830] l2cap_sock_sendmsg: sock ffff8800c7792800, sk ffff88010e7aec00
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574835] l2cap_create_basic_pdu: chan ffff88010e7a9000 len 4
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574841] l2cap_do_send: chan ffff88010e7a9000, skb ffff8800c3bbc900 len 8 priority 0
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574850] rfcomm_session_clear_timer: session ffff880110b72000 state 8
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.574857] rfcomm_process_dlcs: session ffff880110b72000 state 8
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.580975] l2cap_recv_acldata: conn ffff880081914a00 len 8 flags 0x2
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.580984] l2cap_recv_frame: len 4, cid 0x0040
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.580991] l2cap_data_channel: chan ffff88010e7a9000, len 4
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.580998] rfcomm_l2data_ready: ffff88010e7aec00 bytes 4
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.581014] rfcomm_process_rx: session ffff880110b72000 state 8 qlen 1
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.581022] rfcomm_recv_ua: session ffff880110b72000 state 8 dlci 0
Aug  3 11:03:13 fdanis-linux kernel: [ 6380.581030] rfcomm_process_dlcs: session ffff880110b72000 state 8




^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: RFCOMM disconnection problem
  2012-08-03 12:15 RFCOMM disconnection problem Frederic Danis
@ 2012-08-03 12:22 ` Frederic Danis
  2012-08-09 14:29   ` Dean Jenkins
  0 siblings, 1 reply; 5+ messages in thread
From: Frederic Danis @ 2012-08-03 12:22 UTC (permalink / raw)
  To: linux-bluetooth

[-- Attachment #1: Type: text/plain, Size: 917 bytes --]

On 03/08/2012 14:15, Frederic Danis wrote:
> Hello,
>
> When I try to disconnect Blue Stereo 200 headset (from mrhandsfree) from
> my PC, if headset was the initiator of the connection, the low level
> (ACL) is not disconnected.
> The device is still visible whith "hcitool con".
>
> This happens with BlueZ 4.98 or from git upstream, and kernel 3.4.6.
> There is no disconnection problem with kernel 3.2.
>
> I also try to revert change "Bluetooth: Fix RFCOMM session reference
> counting issue" (commit cf33e7 in linux-stable.git) from Octavian
> Purdila in kernel 3.4.6.
> With this kernel I do not get disconnection problem.
>
> You can find attached hcidump traces.

Make a mistake, this was kernel log for l2cap and rfcomm.
Find attached hcidump traces.

Fred


-- 
Frederic Danis                            Open Source Technology Center
frederic.danis@intel.com                              Intel Corporation


[-- Attachment #2: hcidump.txt --]
[-- Type: text/plain, Size: 20090 bytes --]

HCI sniffer - Bluetooth packet analyzer ver 2.2
device: hci0 snap_len: 1028 filter: 0xffffffffffffffff
> HCI Event: Connect Request (0x04) plen 10
    bdaddr 10:04:14:D1:96:1C class 0x240404 type ACL
< HCI Command: Accept Connection Request (0x01|0x0009) plen 7
    bdaddr 10:04:14:D1:96:1C role 0x00
    Role: Master
> HCI Event: Command Status (0x0f) plen 4
    Accept Connection Request (0x01|0x0009) status 0x00 ncmd 1
> HCI Event: Role Change (0x12) plen 8
    status 0x00 bdaddr 10:04:14:D1:96:1C role 0x00
    Role: Master
> HCI Event: Connect Complete (0x03) plen 11
    status 0x00 handle 11 bdaddr 10:04:14:D1:96:1C type ACL encrypt 0x00
< HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2
    handle 11
> HCI Event: Command Status (0x0f) plen 4
    Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 1
> HCI Event: Read Remote Supported Features (0x0b) plen 11
    status 0x00 handle 11
    Features: 0xbf 0xff 0xff 0xfe 0x88 0x3d 0x19 0x82
< HCI Command: Read Remote Extended Features (0x01|0x001c) plen 3
    handle 11 page 1
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 11 slots 5
> HCI Event: Command Status (0x0f) plen 4
    Read Remote Extended Features (0x01|0x001c) status 0x00 ncmd 1
> HCI Event: Read Remote Extended Features (0x23) plen 13
    status 0x00 handle 11 page 1 max 1
    Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
< HCI Command: Remote Name Request (0x01|0x0019) plen 10
    bdaddr 10:04:14:D1:96:1C mode 2 clkoffset 0x0000
> HCI Event: Command Status (0x0f) plen 4
    Remote Name Request (0x01|0x0019) status 0x00 ncmd 1
> HCI Event: Remote Name Req Complete (0x07) plen 255
    status 0x00 bdaddr 10:04:14:D1:96:1C name 'Blue STEREO 200'
> HCI Event: Link Key Request (0x17) plen 6
    bdaddr 10:04:14:D1:96:1C
< HCI Command: Link Key Request Reply (0x01|0x000b) plen 22
    bdaddr 10:04:14:D1:96:1C key 9EF4BDFA68C543865043E004E35D0277
> HCI Event: Command Complete (0x0e) plen 10
    Link Key Request Reply (0x01|0x000b) ncmd 1
    status 0x00 bdaddr 10:04:14:D1:96:1C
> HCI Event: Encrypt Change (0x08) plen 4
    status 0x00 handle 11 encrypt 0x01
> ACL data: handle 11 flags 0x02 dlen 12
    L2CAP(s): Connect req: psm 1 scid 0x0040
< ACL data: handle 11 flags 0x00 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 1 status 0
      Connection pending - No futher information available
< ACL data: handle 11 flags 0x00 dlen 10
    L2CAP(s): Info req: type 2
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 12
    L2CAP(s): Info rsp: type 2 result 1
      Not supported
< ACL data: handle 11 flags 0x00 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 0 status 0
      Connection successful
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 0
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
      MTU 512 
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4
      MTU 512 
> ACL data: handle 11 flags 0x02 dlen 14
    L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 0
      Success
> ACL data: handle 11 flags 0x02 dlen 17
    L2CAP(d): cid 0x0040 len 13 [psm 1]
        SDP SS Req: tid 0x1 len 0x8
          pat uuid-16 0x111f (Handsfree AG)
          max 3
          cont 00
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(d): cid 0x0040 len 14 [psm 1]
        SDP SS Rsp: tid 0x1 len 0x9
          count 1
          handle 0x10002
          cont 00
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 21
    L2CAP(d): cid 0x0040 len 17 [psm 1]
        SDP SA Req: tid 0x2 len 0xc
          handle 0x10002
          max 1016
          aid(s) 0x0004 (ProtocolDescList)
          cont 00
< ACL data: handle 11 flags 0x00 dlen 31
    L2CAP(d): cid 0x0040 len 27 [psm 1]
        SDP SA Rsp: tid 0x2 len 0x16
          count 19
          aid 0x0004 (ProtocolDescList)
             < < uuid-16 0x0100 (L2CAP) > <
             uuid-16 0x0003 (RFCOMM) uint 0xd > >
          cont 00
> ACL data: handle 11 flags 0x02 dlen 12
    L2CAP(s): Disconn req: dcid 0x0040 scid 0x0040
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Disconn rsp: dcid 0x0040 scid 0x0040
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 12
    L2CAP(s): Connect req: psm 3 scid 0x0041
< ACL data: handle 11 flags 0x00 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0041 result 0 status 0
      Connection successful
< ACL data: handle 11 flags 0x00 dlen 16
    L2CAP(s): Config req: dcid 0x0041 flags 0x00 clen 4
      MTU 1013 
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
      MTU 512 
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(s): Config rsp: scid 0x0041 flags 0x00 result 0 clen 4
      MTU 512 
> ACL data: handle 11 flags 0x02 dlen 14
    L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 0
      Success
> ACL data: handle 11 flags 0x02 dlen 8
    L2CAP(d): cid 0x0040 len 4 [psm 3]
      RFCOMM(s): SABM: cr 1 dlci 0 pf 1 ilen 0 fcs 0x1c 
< ACL data: handle 11 flags 0x00 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 3]
      RFCOMM(s): UA: cr 1 dlci 0 pf 1 ilen 0 fcs 0xd7 
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 19
    L2CAP(d): cid 0x0040 len 15 [psm 3]
      RFCOMM(s): PN CMD: cr 1 dlci 0 pf 0 ilen 10 fcs 0x70 mcc_len 8
      dlci 26 frame_type 0 credit_flow 15 pri 7 ack_timer 0
      frame_size 400 max_retrans 0 credits 7
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(d): cid 0x0041 len 14 [psm 3]
      RFCOMM(s): PN RSP: cr 0 dlci 0 pf 0 ilen 10 fcs 0xaa mcc_len 8
      dlci 26 frame_type 0 credit_flow 14 pri 7 ack_timer 0
      frame_size 400 max_retrans 0 credits 7
> ACL data: handle 11 flags 0x02 dlen 8
    L2CAP(d): cid 0x0040 len 4 [psm 3]
      RFCOMM(s): SABM: cr 1 dlci 26 pf 1 ilen 0 fcs 0xe7 
< HCI Command: Authentication Requested (0x01|0x0011) plen 2
    handle 11
> HCI Event: Command Status (0x0f) plen 4
    Authentication Requested (0x01|0x0011) status 0x00 ncmd 1
> HCI Event: Link Key Request (0x17) plen 6
    bdaddr 10:04:14:D1:96:1C
< HCI Command: Link Key Request Reply (0x01|0x000b) plen 22
    bdaddr 10:04:14:D1:96:1C key 9EF4BDFA68C543865043E004E35D0277
> HCI Event: Command Complete (0x0e) plen 10
    Link Key Request Reply (0x01|0x000b) ncmd 1
    status 0x00 bdaddr 10:04:14:D1:96:1C
> HCI Event: Auth Complete (0x06) plen 3
    status 0x00 handle 11
< HCI Command: Set Connection Encryption (0x01|0x0013) plen 3
    handle 11 encrypt 0x01
> HCI Event: Command Status (0x0f) plen 4
    Set Connection Encryption (0x01|0x0013) status 0x00 ncmd 1
> HCI Event: Encryption Key Refresh Complete (0x30) plen 3
    status 0x00 handle 11
> HCI Event: Command Status (0x0f) plen 4
    Set Connection Encryption (0x01|0x0013) status 0x00 ncmd 1
> HCI Event: Encrypt Change (0x08) plen 4
    status 0x00 handle 11 encrypt 0x01
< ACL data: handle 11 flags 0x00 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 3]
      RFCOMM(s): UA: cr 1 dlci 26 pf 1 ilen 0 fcs 0x2c 
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(d): cid 0x0041 len 8 [psm 3]
      RFCOMM(s): MSC CMD: cr 0 dlci 0 pf 0 ilen 4 fcs 0xaa mcc_len 2
      dlci 26 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 0 b2 1 b3 0 len 0
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 13
    L2CAP(d): cid 0x0040 len 9 [psm 3]
      RFCOMM(s): MSC CMD: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
      dlci 26 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 1 b2 0 b3 0 len 14
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(d): cid 0x0041 len 8 [psm 3]
      RFCOMM(s): MSC RSP: cr 0 dlci 0 pf 0 ilen 4 fcs 0xaa mcc_len 2
      dlci 26 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 0 b2 1 b3 0 len 0
> ACL data: handle 11 flags 0x02 dlen 13
    L2CAP(d): cid 0x0040 len 9 [psm 3]
      RFCOMM(s): MSC RSP: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
      dlci 26 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 1 b2 0 b3 0 len 14
< ACL data: handle 11 flags 0x00 dlen 9
    L2CAP(d): cid 0x0041 len 5 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 1 ilen 0 fcs 0x22 credits 33
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 21
    L2CAP(d): cid 0x0040 len 17 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 26 pf 1 ilen 11 fcs 0xf8 credits 8
      0000: 41 54 2b 42 52 53 46 3d  33 30 0d                 AT+BRSF=30.
< ACL data: handle 11 flags 0x00 dlen 22
    L2CAP(d): cid 0x0041 len 18 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 14 fcs 0x3e 
      0000: 0d 0a 2b 42 52 53 46 3a  20 33 35 32 0d 0a        ..+BRSF: 352..
< ACL data: handle 11 flags 0x00 dlen 14
    L2CAP(d): cid 0x0041 len 10 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 6 fcs 0x3e 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 1
> ACL data: handle 11 flags 0x02 dlen 20
    L2CAP(d): cid 0x0040 len 16 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 26 pf 1 ilen 10 fcs 0xf8 credits 2
      0000: 41 54 2b 43 49 4e 44 3d  3f 0d                    AT+CIND=?.
< ACL data: handle 11 flags 0x00 dlen 141
    L2CAP(d): cid 0x0041 len 137 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 132 fcs 0x3e 
      0000: 0d 0a 2b 43 49 4e 44 3a  20 28 22 62 61 74 74 63  ..+CIND: ("battc
      0010: 68 67 22 2c 28 30 2d 35  29 29 2c 28 22 73 69 67  hg",(0-5)),("sig
      0020: 6e 61 6c 22 2c 28 30 2d  35 29 29 2c 28 22 73 65  nal",(0-5)),("se
      0030: 72 76 69 63 65 22 2c 28  30 2c 31 29 29 2c 28 22  rvice",(0,1)),("
      0040: 63 61 6c 6c 22 2c 28 30  2c 31 29 29 2c 28 22 63  call",(0,1)),("c
      0050: 61 6c 6c 73 65 74 75 70  22 2c 28 30 2d 33 29 29  allsetup",(0-3))
      0060: 2c 28 22 63 61 6c 6c 68  65 6c 64 22 2c 28 30 2d  ,("callheld",(0-
      0070: 32 29 29 2c 28 22 72 6f  61 6d 22 2c 28 30 2c 31  2)),("roam",(0,1
      0080: 29 29 0d 0a                                       ))..
< ACL data: handle 11 flags 0x00 dlen 14
    L2CAP(d): cid 0x0041 len 10 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 6 fcs 0x3e 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 19
    L2CAP(d): cid 0x0040 len 15 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 26 pf 1 ilen 9 fcs 0xf8 credits 2
      0000: 41 54 2b 43 49 4e 44 3f  0d                       AT+CIND?.
< ACL data: handle 11 flags 0x00 dlen 32
    L2CAP(d): cid 0x0041 len 28 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 24 fcs 0x3e 
      0000: 0d 0a 2b 43 49 4e 44 3a  20 35 2c 35 2c 31 2c 30  ..+CIND: 5,5,1,0
      0010: 2c 30 2c 30 2c 30 0d 0a                           ,0,0,0..
< ACL data: handle 11 flags 0x00 dlen 14
    L2CAP(d): cid 0x0041 len 10 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 6 fcs 0x3e 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 26
    L2CAP(d): cid 0x0040 len 22 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 26 pf 1 ilen 16 fcs 0xf8 credits 2
      0000: 41 54 2b 43 4d 45 52 3d  33 2c 30 2c 30 2c 31 0d  AT+CMER=3,0,0,1.
< ACL data: handle 11 flags 0x00 dlen 14
    L2CAP(d): cid 0x0041 len 10 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 6 fcs 0x3e 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 1
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 11 slots 1
> ACL data: handle 11 flags 0x02 dlen 20
    L2CAP(d): cid 0x0040 len 16 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 26 pf 1 ilen 10 fcs 0xf8 credits 1
      0000: 41 54 2b 43 4c 49 50 3d  31 0d                    AT+CLIP=1.
< ACL data: handle 11 flags 0x00 dlen 14
    L2CAP(d): cid 0x0041 len 10 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 6 fcs 0x3e 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> ACL data: handle 11 flags 0x02 dlen 19
    L2CAP(d): cid 0x0040 len 15 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 26 pf 1 ilen 9 fcs 0xf8 credits 1
      0000: 41 54 2b 56 47 53 3d 39  0d                       AT+VGS=9.
< ACL data: handle 11 flags 0x00 dlen 14
    L2CAP(d): cid 0x0041 len 10 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 6 fcs 0x3e 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 20
    L2CAP(d): cid 0x0040 len 16 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 26 pf 1 ilen 10 fcs 0xf8 credits 1
      0000: 41 54 2b 56 47 4d 3d 31  30 0d                    AT+VGM=10.
< ACL data: handle 11 flags 0x00 dlen 14
    L2CAP(d): cid 0x0041 len 10 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 26 pf 0 ilen 6 fcs 0x3e 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 1
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Connect req: psm 25 scid 0x0041
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0042 scid 0x0041 result 0 status 0
      Connection successful
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Config req: dcid 0x0042 flags 0x00 clen 0
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0041 flags 0x00 clen 4
      MTU 672 
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(s): Config rsp: scid 0x0042 flags 0x00 result 0 clen 4
      MTU 672 
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 14
    L2CAP(s): Config rsp: scid 0x0041 flags 0x00 result 0 clen 0
      Success
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Connect req: psm 23 scid 0x0042
< ACL data: handle 11 flags 0x00 dlen 6
    L2CAP(d): cid 0x0042 len 2 [psm 25]
      AVDTP(s): Discover cmd: transaction 10 nsp 0x00
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 11 slots 5
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0043 scid 0x0042 result 0 status 0
      Connection successful
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Config req: dcid 0x0043 flags 0x00 clen 0
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0042 flags 0x00 clen 4
      MTU 512 
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(s): Config rsp: scid 0x0043 flags 0x00 result 0 clen 4
      MTU 512 
> ACL data: handle 11 flags 0x02 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 25]
      AVDTP(s): Discover rsp: transaction 10 nsp 0x00
        ACP SEID 1 - Audio Sink
< ACL data: handle 11 flags 0x00 dlen 7
    L2CAP(d): cid 0x0042 len 3 [psm 25]
      AVDTP(s): Capabilities cmd: transaction 11 nsp 0x00
        ACP SEID 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 3
> ACL data: handle 11 flags 0x02 dlen 14
    L2CAP(s): Config rsp: scid 0x0042 flags 0x00 result 0 clen 0
      Success
> ACL data: handle 11 flags 0x02 dlen 20
    L2CAP(d): cid 0x0041 len 16 [psm 25]
      AVDTP(s): Capabilities rsp: transaction 11 nsp 0x00
        Media Transport
        Content Protection
          02 00 
        Media Codec - SBC
          16kHz 32kHz 44.1kHz 48kHz 
          Mono DualChannel Stereo JointStereo 
          4 8 12 16 Blocks
          4 8 Subbands
          SNR Loudness 
          Bitpool Range 2-38
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(d): cid 0x0042 len 14 [psm 25]
      AVDTP(s): Set config cmd: transaction 12 nsp 0x00
        ACP SEID 1 - INT SEID 1
        Media Transport
        Media Codec - SBC
          44.1kHz 
          JointStereo 
          16 Blocks
          8 Subbands
          Loudness 
          Bitpool Range 2-38
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 6
    L2CAP(d): cid 0x0041 len 2 [psm 25]
      AVDTP(s): Set config rsp: transaction 12 nsp 0x00
< ACL data: handle 11 flags 0x00 dlen 7
    L2CAP(d): cid 0x0042 len 3 [psm 25]
      AVDTP(s): Open cmd: transaction 13 nsp 0x00
        ACP SEID 1
> ACL data: handle 11 flags 0x02 dlen 6
    L2CAP(d): cid 0x0041 len 2 [psm 25]
      AVDTP(s): Open rsp: transaction 13 nsp 0x00
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Connect req: psm 25 scid 0x0043
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0044 scid 0x0043 result 0 status 0
      Connection successful
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Config req: dcid 0x0044 flags 0x00 clen 0
> ACL data: handle 11 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0043 flags 0x00 clen 4
      MTU 672 
< ACL data: handle 11 flags 0x00 dlen 18
    L2CAP(s): Config rsp: scid 0x0044 flags 0x00 result 0 clen 4
      MTU 672 
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 14
    L2CAP(s): Config rsp: scid 0x0043 flags 0x00 result 0 clen 0
      Success


< ACL data: handle 11 flags 0x00 dlen 7
    L2CAP(d): cid 0x0042 len 3 [psm 25]
      AVDTP(s): Close cmd: transaction 14 nsp 0x00
        ACP SEID 1
> ACL data: handle 11 flags 0x02 dlen 6
    L2CAP(d): cid 0x0041 len 2 [psm 25]
      AVDTP(s): Close rsp: transaction 14 nsp 0x00
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Disconn req: dcid 0x0044 scid 0x0043
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 12
    L2CAP(s): Disconn rsp: dcid 0x0044 scid 0x0043
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Disconn req: dcid 0x0042 scid 0x0041
< ACL data: handle 11 flags 0x00 dlen 12
    L2CAP(s): Disconn req: dcid 0x0043 scid 0x0042
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 12
    L2CAP(s): Disconn rsp: dcid 0x0042 scid 0x0041
> ACL data: handle 11 flags 0x02 dlen 12
    L2CAP(s): Disconn rsp: dcid 0x0043 scid 0x0042
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 11 slots 1
> HCI Event: Mode Change (0x14) plen 6
    status 0x00 handle 11 mode 0x02 interval 2048
    Mode: Sniff


< ACL data: handle 11 flags 0x00 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 3]
      RFCOMM(s): DISC: cr 0 dlci 26 pf 1 ilen 0 fcs 0x67 
< HCI Command: Exit Sniff Mode (0x02|0x0004) plen 2
    handle 11
> HCI Event: Command Status (0x0f) plen 4
    Exit Sniff Mode (0x02|0x0004) status 0x00 ncmd 1
> ACL data: handle 11 flags 0x02 dlen 8
    L2CAP(d): cid 0x0040 len 4 [psm 3]
      RFCOMM(s): UA: cr 0 dlci 26 pf 1 ilen 0 fcs 0x4d 
< ACL data: handle 11 flags 0x00 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 3]
      RFCOMM(s): DISC: cr 0 dlci 0 pf 1 ilen 0 fcs 0x9c 
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 11 slots 5
> HCI Event: Mode Change (0x14) plen 6
    status 0x00 handle 11 mode 0x00 interval 0
    Mode: Active
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 8
    L2CAP(d): cid 0x0040 len 4 [psm 3]
      RFCOMM(s): UA: cr 0 dlci 0 pf 1 ilen 0 fcs 0xb6 
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 11 slots 1
> HCI Event: Mode Change (0x14) plen 6
    status 0x00 handle 11 mode 0x02 interval 2048
    Mode: Sniff



^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: RFCOMM disconnection problem
  2012-08-03 12:22 ` Frederic Danis
@ 2012-08-09 14:29   ` Dean Jenkins
  2012-08-09 14:46     ` Andrei Emeltchenko
  0 siblings, 1 reply; 5+ messages in thread
From: Dean Jenkins @ 2012-08-09 14:29 UTC (permalink / raw)
  To: Frederic Danis; +Cc: linux-bluetooth

On 3 August 2012 13:22, Frederic Danis <frederic.danis@linux.intel.com> wrote:
> On 03/08/2012 14:15, Frederic Danis wrote:
>>
>> Hello,
>>
>> When I try to disconnect Blue Stereo 200 headset (from mrhandsfree) from
>> my PC, if headset was the initiator of the connection, the low level
>> (ACL) is not disconnected.
>> The device is still visible whith "hcitool con".
>>
>> This happens with BlueZ 4.98 or from git upstream, and kernel 3.4.6.
>> There is no disconnection problem with kernel 3.2.
>>
>> I also try to revert change "Bluetooth: Fix RFCOMM session reference
>> counting issue" (commit cf33e7 in linux-stable.git) from Octavian
>> Purdila in kernel 3.4.6.
>> With this kernel I do not get disconnection problem.
>>
>> You can find attached hcidump traces.
>
>
> Make a mistake, this was kernel log for l2cap and rfcomm.
>
> Find attached hcidump traces.
>
> Fred
>
>
> --
> Frederic Danis                            Open Source Technology Center
> frederic.danis@intel.com                              Intel Corporation
>

Hi Fred,

IMHO, kernel.org's rfcomm session refcnt is fundamentally broken and
is in fact redundant. Search back in the mailing list for my previous
proposed fixes.

One obvious failure of the rfcomm session refcnt is that the refcnt
counter either starts with a value of 0 or 1 depending on which peer
initiated the connection request, that is wrong. The initiator
direction is not relevant for the session as connect and disconnect
are independent events. The refcnt should start with a value of 1 in
all cases.

I am using a 2-core ARM environment that is under high processor
loading. The rfcomm session refcnt caused kernel crashes. I used a
2.6.34 kernel but the latest 3.5-RC1 still has the poor rfcomm code.
My solution was to remove the rfcomm session refcnt and to ensure that
the freeing of the rfcomm session pointer was propagated through-out
the rfcomm core code. Some kernel crashes were due to reuse of the
freed rfcomm session pointer.

I intend to release a patchset of rfcomm fixes.

Therefore, IMHO the fix "Bluetooth: Fix RFCOMM session reference
counting issue" (commit cf33e7 in linux-stable.git) from Octavian
Purdila in kernel 3.4.6 is in fact not fixing the root cause and
introduces a misbehaviour of the refcnt. In our project, we rejected
this commit because disconnections failed.

Regards,
Dean

-- 
Dean Jenkins
Embedded Software Engineer
Professional Services UK/EMEA
MontaVista Software, LLC

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: RFCOMM disconnection problem
  2012-08-09 14:29   ` Dean Jenkins
@ 2012-08-09 14:46     ` Andrei Emeltchenko
  2012-08-10  9:02       ` Dean Jenkins
  0 siblings, 1 reply; 5+ messages in thread
From: Andrei Emeltchenko @ 2012-08-09 14:46 UTC (permalink / raw)
  To: Dean Jenkins; +Cc: Frederic Danis, linux-bluetooth

Hi Dean,

On Thu, Aug 09, 2012 at 03:29:18PM +0100, Dean Jenkins wrote:
> One obvious failure of the rfcomm session refcnt is that the refcnt
> counter either starts with a value of 0 or 1 depending on which peer
> initiated the connection request, that is wrong. The initiator
> direction is not relevant for the session as connect and disconnect
> are independent events. The refcnt should start with a value of 1 in
> all cases.
> 
> I am using a 2-core ARM environment that is under high processor
> loading. The rfcomm session refcnt caused kernel crashes. I used a
> 2.6.34 kernel but the latest 3.5-RC1 still has the poor rfcomm code.
> My solution was to remove the rfcomm session refcnt and to ensure that
> the freeing of the rfcomm session pointer was propagated through-out
> the rfcomm core code. Some kernel crashes were due to reuse of the
> freed rfcomm session pointer.

Maybe it does make sense to fix refcounting instead of removing?

Best regards 
Andrei Emeltchenko 

> 
> I intend to release a patchset of rfcomm fixes.
> 
> Therefore, IMHO the fix "Bluetooth: Fix RFCOMM session reference
> counting issue" (commit cf33e7 in linux-stable.git) from Octavian
> Purdila in kernel 3.4.6 is in fact not fixing the root cause and
> introduces a misbehaviour of the refcnt. In our project, we rejected
> this commit because disconnections failed.
> 


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: RFCOMM disconnection problem
  2012-08-09 14:46     ` Andrei Emeltchenko
@ 2012-08-10  9:02       ` Dean Jenkins
  0 siblings, 0 replies; 5+ messages in thread
From: Dean Jenkins @ 2012-08-10  9:02 UTC (permalink / raw)
  To: Andrei Emeltchenko, Dean Jenkins, Frederic Danis, linux-bluetooth

On 9 August 2012 15:46, Andrei Emeltchenko
<andrei.emeltchenko.news@gmail.com> wrote:
> Hi Dean,
>
> On Thu, Aug 09, 2012 at 03:29:18PM +0100, Dean Jenkins wrote:
>> One obvious failure of the rfcomm session refcnt is that the refcnt
>> counter either starts with a value of 0 or 1 depending on which peer
>> initiated the connection request, that is wrong. The initiator
>> direction is not relevant for the session as connect and disconnect
>> are independent events. The refcnt should start with a value of 1 in
>> all cases.
>>
>> I am using a 2-core ARM environment that is under high processor
>> loading. The rfcomm session refcnt caused kernel crashes. I used a
>> 2.6.34 kernel but the latest 3.5-RC1 still has the poor rfcomm code.
>> My solution was to remove the rfcomm session refcnt and to ensure that
>> the freeing of the rfcomm session pointer was propagated through-out
>> the rfcomm core code. Some kernel crashes were due to reuse of the
>> freed rfcomm session pointer.
>
> Maybe it does make sense to fix refcounting instead of removing?
>
Hi Andrei,

The existing rfcomm session state machine is capable of determining
when to delete the rfcomm session structure. IMHO the refcnt is an
unnecessary complication. I have fixed rfcomm for our project by
removing the refcnt and ensuring no code can reuse a freed rfcomm
session pointer. This code I have already sent to the mailing list.

In order to get rfcomm to fail, high processor load is necessary
during disconnections to ensure that some of the loops in rfcomm
process more than 1 thing. It is because there are multiple copies of
the rfcomm session pointer s that failure occurs eg. double rfcomm
session free.

Here is an example in net/bluetooth/rfcomm/core.c:

static inline void rfcomm_process_rx(struct rfcomm_session *s)
{
	struct socket *sock = s->sock;
	struct sock *sk = sock->sk;
	struct sk_buff *skb;

	BT_DBG("session %p state %ld qlen %d", s, s->state,
skb_queue_len(&sk->sk_receive_queue));

	/* Get data directly from socket receive queue without copying it. */
	while ((skb = skb_dequeue(&sk->sk_receive_queue))) {
		skb_orphan(skb);
		if (!skb_linearize(skb))
			rfcomm_recv_frame(s, skb);
		else
			kfree_skb(skb);
	}

	if (sk->sk_state == BT_CLOSED) {
		if (!s->initiator)
			rfcomm_session_put(s);

		rfcomm_session_close(s, sk->sk_err);
	}
}

In rfcomm_process_rx(), you can see there is a while loop that causes
frames to be analysed and actioned in rfcomm_recv_frame(). This action
may cause the rfcomm session pointer to be freed because the rfcomm
session refcnt has reached zero. Therefore, the s pointer is now
invalid in the scope of rfcomm_process_rx() because the underlying
session structure was freed. Unfortunately,  if the socket state is
also detected as BT_CLOSED then !s->initiator may cause a crash or at
least accesses wrong data as the s pointer is invalid (pointing to
freed memory or reallocated memory). The refcnt in
rfcomm_session_put(s) is also invalid as s is invalid. In fact looking
at the initiator value is wrong for the rfcomm session. I suspect this
was a workaround that did not fix the root cause.

In practice, this failure scenario is difficult to reproduce (we hit
it in our embedded environment). It requires the socket to be in the
BT_CLOSED at the same time as the rfcomm session has been freed in a
single run of rfcomm_process_rx(). This is why high processor loading
triggers the malfunction because rfcomm_process_rx() maybe pre-empted
or time-sliced so rfcomm_process_rx() takes longer to complete than
normal. This gives the opportunity for the socket state to change to
BT_CLOSED during the run-time of rfcomm_process_rx().

In other words, the refcnt going to zero does not prevent copies of
the rfcomm session pointer s that now points to freed memory (or
reallocated memory) from being erroneously reused.

You can also see

		if (!s->initiator)
			rfcomm_session_put(s);

		rfcomm_session_close(s, sk->sk_err);

If rfcomm_session_put(s) succeeds in causing the refcnt to go to zero,
the rfcomm session structure will be freed. s is now invalid.
Unfortunately, rfcomm_session_close(s, sk->sk_err) reuses the s
pointer with a potential for a crash.

The refcnt could be fixed but fixing it will show it to be unnecessary
code IMHO. One of the weaknesses in the code is not managing the s
pointer after the session has been freed.

I do intend to release a patchset of all our rfcomm changes.

I welcome any comments.

Regards,
Dean

> Best regards
> Andrei Emeltchenko
>
>>
>> I intend to release a patchset of rfcomm fixes.
>>
>> Therefore, IMHO the fix "Bluetooth: Fix RFCOMM session reference
>> counting issue" (commit cf33e7 in linux-stable.git) from Octavian
>> Purdila in kernel 3.4.6 is in fact not fixing the root cause and
>> introduces a misbehaviour of the refcnt. In our project, we rejected
>> this commit because disconnections failed.
>>
>


-- 
Dean Jenkins
Embedded Software Engineer
Professional Services UK/EMEA
MontaVista Software, LLC

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2012-08-10  9:02 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-08-03 12:15 RFCOMM disconnection problem Frederic Danis
2012-08-03 12:22 ` Frederic Danis
2012-08-09 14:29   ` Dean Jenkins
2012-08-09 14:46     ` Andrei Emeltchenko
2012-08-10  9:02       ` Dean Jenkins

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.