[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[bluetooth-dev] OpenBT HCI LINK_KEY_REQUEST problem



Hi all,

We are trying to use BlueMod to connect to Ericsson T39 phone which
provides DUNP.
We manager to get connection if T39 is running in disovery mode, but
fail if not.

I enable the log in OpenBT, and below is what I am trying to do.
The number which begin with 9439 in the log is the time.

# btcon -d /dev/ttyBT5 -a 00:80:37:d6:76:99 -S 1
btdev  /dev/ttyBT5
Connecting to bd:  0:80:37:d6:76:99
Using rfcomm server ch: 1
Connecting to 00:80:37:D6:76:99 on line 5
Connect failed [General Failure (1)]
# cat /proc/kmsg
<4>BT (driver) bt_open: Line 7
<4>BT (driver) Registering tty on line 7 (btcon)
<4>BT (driver) Now 2 open fd:s for ttyBTC [btcon]
<4>BT (driver) __bt_ioctl: BTCONNECT
<4>BT (driver) bt_connect: Connecting srv ch 1 on line 5
<4>
<4>[943959904,400000<177490000>]  Remote BD:  (6):
<4>0x00 0x80 0x37 0xd6 0x76 0x99
<4>          RFCOMM rfcomm_connect_req: server channel:1, line:5
<4>    L2CAP l2ca_connect_req
<4>
<4>[943959904,410000<010000>]  l2ca_connect_req: sent to bd  (6):
<4>0x00 0x80 0x37 0xd6 0x76 0x99
<4>    L2CAP get_con: look for connections in state ANY_STATE (7)
<4>
<4>[943959904,410000<000000>]  get_con: look for bd :  (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>    L2CAP get_con: connection not found
<4>    L2CAP get_lcon: lcid 65 con_list.count = 0
<4>    L2CAP get_lcon: connection lcid : 65 not found
<4>    L2CAP create_con: rcid 0
<4>    L2CAP init_flow
<4>
<4>[943959904,410000<000000>]  bd (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>show_con: insert_con (65:0) [CLOSED] [RFCOMM] r_mtu[672] C[yes]
link_up[no]
<4>    L2CAP insert_con: now 1 connections
<4>    L2CAP l2ca_connect_req: create new baseband link
<4>
<4>[943959904,420000<010000>]  lp_connect_req: bd address is:  (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>    L2CAP get_con: look for connections in state ANY_STATE (7)
<4>
<4>[943959904,420000<000000>]  get_con: look for bd :  (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>
<4>[943959904,420000<000000>]  get_con: found bd  (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>HCI: create_connection
<4>HCI: insert_cmd
<4>l2ca_connect_req: wait baseband, sleep on wq 0x32a7f8
<4>HCI: send_cmd_queue: start: Num_HCI_Command_Packets=1
<4>
<4>[943959904,430000<010000>]  send_cmd_queue:  (17):
<4>0x01 0x05 0x04 0x0d 0x99 0x76 0xd6 0x37 0x80 0x00 0x18 0xcc 0x00 0x00
0x00 0x
00
<4>0x01
<4>[943959904,430000<000000>] BT DATA <--|X|     22
<4>
<4>[943959904,430000<000000>]  <--|X| (22):
<4>0xc0 0x8d 0x05 0x01 0x6c 0x05 0x04 0x0d 0x99 0x76 0xd6 0x37 0x80 0x00
0x18 0x
cc
<4>0x00 0x00 0x00 0x00 0x01 0xc0
<4>HCI: send_cmd_queue: end : 0 cmds left in queue
<4>[943959904,430000<000000>] BT DATA -->|X|      6
<4>
<4>[943959904,430000<000000>]  -->|X| (6):
<4>0xc0 0x30 0x00 0x00 0xcf 0xc0
<4>[943959904,440000<010000>] BT DATA -->|X|     12
<4>
<4>[943959904,440000<000000>]  -->|X| (12):
<4>0xc0 0xb1 0x65 0x00 0xe9 0x0f 0x04 0x00 0x01 0x05 0x04 0xc0
<4>[943959904,440000<000000>] BT DATA <--|X|      6
<4>
<4>[943959904,440000<000000>]  <--|X| (6):
<4>0xc0 0x10 0x00 0x00 0xef 0xc0
<4>HCI: hci_receive_event: Received event 0x0f with len:4
<4>
<4>[943959904,440000<000000>]  process_event (4):
<4>0x00 0x01 0x05 0x04
<4>HCI: release_cmd_timer
<4>HCI: process_event: COMMAND_STATUS
<4>HCI: update_nhcp: Num_HCI_Command_Packets=1
<4>HCI: send_cmd_queue: start: Num_HCI_Command_Packets=1
<4>HCI: send_cmd_queue: end : 0 cmds left in queue
<4>[943959908,920000<4480000>] BT DATA -->|X|     14
<4>
<4>[943959908,920000<000000>]  -->|X| (14):
<4>0xc0 0xb2 0x85 0x00 0xc8 0x17 0x06 0x99 0x76 0xd6 0x37 0x80 0x00 0xc0
<4>[943959908,920000<000000>] BT DATA <--|X|      6
<4>
<4>[943959908,920000<000000>]  <--|X| (6):
<4>0xc0 0x18 0x00 0x00 0xe7 0xc0
<4>HCI: hci_receive_event: Received event 0x17 with len:6
<4>
<4>[943959908,920000<000000>]  process_event (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>HCI: process_event: LINK_KEY_REQUEST
<4>Called sec_man_event user:0 event:17
<4>wake_up process 3 (ksoftirqd_CPU0) awakening
<4>wake_up process 3 (ksoftirqd_CPU0) woke up
<4>sec_man_read: Returning 36 bytes
<4>BT (driver) bt_open: Line 7
<4>BT (driver) Registering tty on line 7 (sec_manager)
<4>BT (driver) Now 3 open fd:s for ttyBTC [sec_manager]
<4>[943959958,880000<49960000>] BT DATA -->|X|     19
<4>
<4>[943959958,880000<000000>]  -->|X| (19):
<4>0xc0 0xb3 0xd5 0x00 0x77 0x03 0x0b 0x08 0x28 0x00 0x99 0x76 0xd6 0x37
0x80 0x
00
<4>0x01 0x00 0xc0
<4>[943959958,880000<000000>] BT DATA <--|X|      6
<4>
<4>[943959958,880000<000000>]  <--|X| (6):
<4>0xc0 0x20 0x00 0x00 0xdf 0xc0
<4>HCI: hci_receive_event: Received event 0x03 with len:11
<4>
<4>[943959958,880000<000000>]  process_event (11):
<4>0x08 0x28 0x00 0x99 0x76 0xd6 0x37 0x80 0x00 0x01 0x00
<4>HCI: process_event: CONNECTION_COMPLETE: Connection Timeout
<4>    L2CAP lp_connect_cfm: Connection Timeout (hci_handle : 40)
<4>    L2CAP lp_connect_cfm: bd 00:80:37:D6:76:99
<4>    L2CAP get_con: look for connections in state CLOSED (0)
<4>
<4>[943959958,880000<000000>]  get_con: look for bd :  (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>
<4>[943959958,880000<000000>]  get_con: con_list bd  (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>    L2CAP lp_connect_cfm: (neg) Connection Timeout
<4>lp_connect_cfm (neg), wake up wq 0x32a7f8
<4>    L2CAP l2ca_connect_cfm: rCID 0, result 65544
<4>    L2CAP get_upper: Try to retrieve psm 0x3
<4>    L2CAP get_upper: Actually got psm:0x3
<4>          RFCOMM rfcomm_connect_cfm: status 65544
<4>          RFCOMM rfcomm_reset_con: line 5
<4>BT (driver) bt_connect_cfm: Line 5 [RCOMM]
<4>BT SYS: process_event: CONNECTION_COMPLETE Connection Timeout
<4>BT SYS: ERROR: reset_hci_con_bd: Didn't find connection with con_hdl
40
<4>l2ca_connect_req: wait baseband, woke up !
<4>BT SYS: ERROR: l2ca_connect_req: lp_connect_req failed, no connection
(status
 8)
<4>show_con: delete_con (65:0) [CLOSED] [RFCOMM] r_mtu[672] C[yes]
link_up[no]
<4>    L2CAP Now connection list is empty !
<4>BT SYS: ERROR: rfcomm_connect_req: l2ca_connect_req failed
<4>BT (driver) bt_connect: Failed
<4>BT (driver) bt_close: Line 7
<4>BT (driver) Unregistering tty on line 7
<4>BT (driver) __bt_ioctl: HCIPINCODEREPLY
<4>
<4>[943959958,910000<030000>]  hci_pin_code_request_reply: New pin is
<4> (4):
<4>0x38 0x38 0x38 0x38
<4>
<4>[943959958,910000<000000>]  hci_pin_code_request_reply:  BD_addr (6):
<4>0x99 0x76 0xd6 0x37 0x80 0x00
<4>
<4>[943959958,910000<000000>]  hci_pin_code_request_reply:  pin (4):
<4>0x38 0x38 0x38 0x38
<4>HCI: start_cmd_timer
<4>HCI: insert_cmd
<4>HCI: send_cmd_queue: start: Num_HCI_Command_Packets=1
<4>
<4>[943959958,920000<010000>]  send_cmd_queue:  (27):
<4>0x01 0x0d 0x04 0x17 0x99 0x76 0xd6 0x37 0x80 0x00 0x04 0x38 0x38 0x38
0x38 0x
40
<4>0x80 0x00 0x00 0x40 0x80 0x00 0x00 0x00 0x0d 0xcd 0x00
<4>[943959958,920000<000000>] BT DATA <--|X|     32
<4>
<4>[943959958,920000<000000>]  <--|X| (32):
<4>0xc0 0xa6 0xa5 0x01 0xb3 0x0d 0x04 0x17 0x99 0x76 0xd6 0x37 0x80 0x00
0x04 0x
38
<4>0x38 0x38 0x38 0x40 0x80 0x00 0x00 0x40 0x80 0x00 0x00 0x00 0x0d 0xcd
0x00 0x
c0
<4>HCI: send_cmd_queue: end : 0 cmds left in queue
<4>[943959958,930000<010000>] BT DATA -->|X|      6
<4>
<4>[943959958,930000<000000>]  -->|X| (6):
<4>0xc0 0x38 0x00 0x00 0xc7 0xc0
<4>[943959958,940000<010000>] BT DATA -->|X|     18
<4>
<4>[943959958,940000<000000>]  -->|X| (18):
<4>0xc0 0xbc 0xc5 0x00 0x7e 0x0e 0x0a 0x01 0x0d 0x04 0x02 0x99 0x76 0xd6
0x37 0x
80
<4>0x00 0xc0
<4>[943959958,940000<000000>] BT DATA <--|X|      6
<4>
<4>[943959958,940000<000000>]  <--|X| (6):
<4>0xc0 0x28 0x00 0x00 0xd7 0xc0
<4>HCI: hci_receive_event: Received event 0x0e with len:10
<4>
<4>[943959958,940000<000000>]  process_event (10):
<4>0x01 0x0d 0x04 0x02 0x99 0x76 0xd6 0x37 0x80 0x00
<4>HCI: process_event: COMMAND_COMPLETE
<4>HCI: <CC>
<4>HCI: release_cmd_timer
<4>HCI: process_return_param: PIN_CODE_REQUEST_REPLY
<4>BT SYS: ERROR: process_return_param: PIN_CODE_REQUEST_REPLY No
Connection
<4>HCI: update_nhcp: Num_HCI_Command_Packets=1
<4>BT (driver) bt_close: Line 7
<4>BT (driver) Unregistering tty on line 7
<4>sec_man_read:  Someone is trying to read  36 bytes from sec proc-file
<4>sec_man_read: No response yet, going to sleep
<4>HCI: send_cmd_queue: start: Num_HCI_Command_Packets=1
<4>HCI: send_cmd_queue: end : 0 cmds left in queue


From the log, OpenBT fail to answer the HCI LINK_KEY_REQUEST, it looks
like that the previous ioctl() in /bin/btcon blocks the ioctl() in
/bin/sec_manager, /bin/sec_manager can't anwser anything until
/bin/btcon closes /dev/ttyBTC.

Any idea to solve the problem?
-
To unsubscribe from this list: send the line "unsubscribe bluetooth-dev" in
the body of a message to majordomo@xxxxxxx.com