pairing issues: PIN code negative reply: Device or resource busy

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

 



Hi,

I occasionally have trouble pairing my phone with BlueZ running on an
embedded platform.  The issue I see is the line "PIN code negative
reply: Device or resource busy" in the debug output.  It looks like a
transaction with the agent is still ongoing while another one is
requested, which is apparently not allowed by the code.  I think the
issue is worse when I enable debug output from BlueZ, so I'm guessing
the issue could be timing dependent.  I've pasted both the debug
output as well as a hcidump.

Of note, my phone thinks it is paired with BlueZ, but I've removed the
pairing from BlueZ.  Not sure if this is making the code paths any
different than a clean pairing.

Any thoughts on how to get the agent freed up so I can get the pin
code processed?  The agent in this case only ever returns a static pin
code, so by and large, the separate agent is actually not needed in my
use case.

Thanks,
Mike


bluetoothd[599]: plugins/hciops.c:conn_complete() status 0x00
bluetoothd[599]: src/adapter.c:adapter_get_device() 00:17:E3:3B:4F:DD
bluetoothd[599]: src/adapter.c:adapter_create_device() 00:17:E3:3B:4F:DD
bluetoothd[599]: src/device.c:device_create() Creating device
/org/bluez/599/hci0/dev_00_17_E3_3B_4F_DD
bluetoothd[599]: src/device.c:btd_device_ref() 0x2a0a9fb8: ref=1
bluetoothd[599]: src/device.c:device_set_temporary() temporary 1
bluetoothd[599]: plugins/hciops.c:remote_features_information() hci0 status 0
bluetoothd[599]: plugins/hciops.c:remote_name_information() hci0 status 0
bluetoothd[599]: audio/avdtp.c:avdtp_confirm_cb() AVDTP: incoming
connect from 00:17:E3:3B:4F:DD
bluetoothd[599]: src/adapter.c:adapter_get_device() 00:17:E3:3B:4F:DD
bluetoothd[599]: src/device.c:btd_device_ref() 0x2a0a9fb8: ref=2
bluetoothd[599]: audio/device.c:audio_device_register() Registered
interface org.bluez.Audio on path
/org/bluez/599/hci0/dev_00_17_E3_3B_4F_DD
bluetoothd[599]: src/device.c:device_probe_drivers() Probing drivers
for 00:17:E3:3B:4F:DD
bluetoothd[599]: audio/manager.c:handle_uuid() server not enabled for
0000110d-0000-1000-8000-00805f9b34fb (0x110d)
bluetoothd[599]: src/agent.c:agent_authorize() authorize request was
sent for /org/bluez/599/hci0/dev_00_17_E3_3B_4F_DD
bluetoothd[599]: plugins/hciops.c:link_key_request() hci0 dba 00:17:E3:3B:4F:DD
bluetoothd[599]: plugins/hciops.c:get_auth_info() hci0 dba 00:17:E3:3B:4F:DD
bluetoothd[599]: plugins/hciops.c:link_key_request() kernel auth
requirements = 0x04
bluetoothd[599]: plugins/hciops.c:link_key_request() Matching key not found
bluetoothd[599]: plugins/hciops.c:pin_code_request() hci0 PIN request
for 00:17:E3:3B:4F:DD
bluetoothd[599]: src/adapter.c:adapter_get_device() 00:17:E3:3B:4F:DD
bluetoothd[599]: src/device.c:device_request_authentication()
Requesting agent authentication for 00:17:E3:3B:4F:DD
bluetoothd[599]: Failed requesting authentication
bluetoothd[599]: PIN code negative reply: Device or resource busy
bluetoothd[599]: plugins/hciops.c:auth_complete() hci0 status 24
bluetoothd[599]: plugins/hciops.c:bonding_complete() status 0x18
bluetoothd[599]: src/device.c:device_bonding_complete() bonding (nil)
status 0x18
bluetoothd[599]: audio/avdtp.c:avdtp_connect_cb() AVDTP: connected
signaling channel to 00:17:E3:3B:4F:DD
bluetoothd[599]: audio/avdtp.c:avdtp_connect_cb() AVDTP imtu=672, omtu=0
bluetoothd[599]: audio/avdtp.c:session_cb()
bluetoothd[599]: audio/avdtp.c:connection_lost() Disconnected from
00:17:E3:3B:4F:DD
bluetoothd[599]: audio/avdtp.c:avdtp_unref() 0x2a0aa208: ref=0
bluetoothd[599]: audio/avdtp.c:avdtp_unref() 0x2a0aa208: freeing
session and removing from list
bq27200-battery 1-0055: error reading voltage
bluetoothd[599]: plugins/hciops.c:disconn_complete() handle 1 status 0x00
bluetoothd[599]: src/event.c:btd_event_disconn_complete()
bluetoothd[599]: src/adapter.c:adapter_remove_connection()
bluetoothd[599]: src/adapter.c:adapter_remove_connection() Removing
temporary device /org/bluez/599/hci0/dev_00_17_E3_3B_4F_DD
bluetoothd[599]: src/device.c:device_remove() Removing device
/org/bluez/599/hci0/dev_00_17_E3_3B_4F_DD
bluetoothd[599]: audio/unix.c:unix_device_removed()
unix_device_removed(0x2a0a9ee0)
bluetoothd[599]: src/device.c:btd_device_unref() 0x2a0a9fb8: ref=1
bluetoothd[599]: src/device.c:btd_device_unref() 0x2a0a9fb8: ref=0
bluetoothd[599]: src/device.c:device_free() 0x2a0a9fb8

> HCI Event: Connect Request (0x04) plen 10
    bdaddr 00:17:E3:3B:4F:DD class 0x5a2204 type ACL
< HCI Command: Accept Connection Request (0x01|0x0009) plen 7
    bdaddr 00:17:E3:3B:4F:DD 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 00:17:E3:3B:4F:DD role 0x00
    Role: Master
> HCI Event: Connect Complete (0x03) plen 11
    status 0x00 handle 1 bdaddr 00:17:E3:3B:4F:DD type ACL encrypt 0x00
> HCI Event: Page Scan Repetition Mode Change (0x20) plen 7
    bdaddr 00:17:E3:3B:4F:DD mode 1
< HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2
    handle 1
> HCI Event: Command Status (0x0f) plen 4
    Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 1
> ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Connect req: psm 1 scid 0x0040
< ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 1 status 0
      Connection pending - No futher information available
< ACL data: handle 1 flags 0x02 dlen 10
    L2CAP(s): Info req: type 2
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 1 slots 5
> HCI Event: Read Remote Supported Features (0x0b) plen 11
    status 0x00 handle 1
    Features: 0xff 0xff 0x2d 0x78 0x18 0x18 0x00 0x80
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 2
< HCI Command: Remote Name Request (0x01|0x0019) plen 10
    bdaddr 00:17:E3:3B:4F:DD mode 2 clkoffset 0x0000
> HCI Event: Command Status (0x0f) plen 4
    Remote Name Request (0x01|0x0019) status 0x00 ncmd 1
> ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Info rsp: type 2 result 0
      Extended feature mask 0x0000
> HCI Event: Remote Name Req Complete (0x07) plen 255
    status 0x00 bdaddr 00:17:E3:3B:4F:DD name 'Sparta'
< ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 0 status 0
      Connection successful
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
      MTU 1024
< ACL data: handle 1 flags 0x02 dlen 18
    L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4
      MTU 1024
< ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 0
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 2
> ACL data: handle 1 flags 0x02 dlen 14
    L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 0
      Success
> ACL data: handle 1 flags 0x02 dlen 37
    L2CAP(d): cid 0x0040 len 33 [psm 1]
        SDP SSA Req: tid 0x1 len 0x1c
          pat uuid-16 0x110b (AudioSink)
          max 128
          aid(s) 0x0000 (SrvRecHndl) 0x0001 (SrvClassIDList) 0x0002
(SrvRecState) 0x0006 (LangBaseAttrIDList) 0x0009 (BTProfileDescList)
0x0311 (SuppFeatures)
          cont 00
< ACL data: handle 1 flags 0x02 dlen 51
    L2CAP(d): cid 0x0040 len 47 [psm 1]
        SDP SSA Rsp: tid 0x1 len 0x2a
          count 39
          record #0
              aid 0x0000 (SrvRecHndl)
                 uint 0x10001
              aid 0x0001 (SrvClassIDList)
                 < uuid-16 0x110b (AudioSink) >
              aid 0x0009 (BTProfileDescList)
                 < < uuid-16 0x110d (AdvAudio) uint 0x102 > >
              aid 0x0311 (SuppFeatures)
                 uint 0xf
          cont 00
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 37
    L2CAP(d): cid 0x0040 len 33 [psm 1]
        SDP SSA Req: tid 0x7a5 len 0x1c
          pat uuid-16 0x111e (Handsfree)
          max 128
          aid(s) 0x0000 (SrvRecHndl) 0x0001 (SrvClassIDList) 0x0002
(SrvRecState) 0x0006 (LangBaseAttrIDList) 0x0009 (BTProfileDescList)
0x0311 (SuppFeatures)
          cont 00
< ACL data: handle 1 flags 0x02 dlen 48
    L2CAP(d): cid 0x0040 len 44 [psm 1]
        SDP SSA Rsp: tid 0x7a5 len 0x27
          count 36
          record #0
              aid 0x0000 (SrvRecHndl)
                 uint 0x10000
              aid 0x0001 (SrvClassIDList)
                 < uuid-16 0x111e (Handsfree) uuid-16 0x1203 (Audio) >
              aid 0x0009 (BTProfileDescList)
                 < < uuid-16 0x111e (Handsfree) uint 0x105 > >
          cont 00
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 37
    L2CAP(d): cid 0x0040 len 33 [psm 1]
        SDP SSA Req: tid 0x7a7 len 0x1c
          pat uuid-16 0x1108 (Headset)
          max 128
          aid(s) 0x0000 (SrvRecHndl) 0x0001 (SrvClassIDList) 0x0002
(SrvRecState) 0x0006 (LangBaseAttrIDList) 0x0009 (BTProfileDescList)
0x0311 (SuppFeatures)
          cont 00
< ACL data: handle 1 flags 0x02 dlen 14
    L2CAP(d): cid 0x0040 len 10 [psm 1]
        SDP SSA Rsp: tid 0x7a7 len 0x5
          count 2
          cont 00
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 21
    L2CAP(d): cid 0x0040 len 17 [psm 1]
        SDP SA Req: tid 0x7a9 len 0xc
          handle 0x10000
          max 128
          aid(s) 0x0004 (ProtocolDescList)
          cont 00
< ACL data: handle 1 flags 0x02 dlen 31
    L2CAP(d): cid 0x0040 len 27 [psm 1]
        SDP SA Rsp: tid 0x7a9 len 0x16
          count 19
          aid 0x0004 (ProtocolDescList)
             < < uuid-16 0x0100 (L2CAP) > <
             uuid-16 0x0003 (RFCOMM) uint 0x7 > >
          cont 00
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 21
    L2CAP(d): cid 0x0040 len 17 [psm 1]
        SDP SA Req: tid 0x7ab len 0xc
          handle 0x10001
          max 128
          aid(s) 0x0004 (ProtocolDescList)
          cont 00
< ACL data: handle 1 flags 0x02 dlen 35
    L2CAP(d): cid 0x0040 len 31 [psm 1]
        SDP SA Rsp: tid 0x7ab len 0x1a
          count 23
          aid 0x0004 (ProtocolDescList)
             < < uuid-16 0x0100 (L2CAP) uint 0x19 > <
             uuid-16 0x0019 (AVDTP) uint 0x102 > >
          cont 00
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Connect req: psm 3 scid 0x0041
< ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0041 scid 0x0041 result 0 status 0
      Connection successful
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0041 flags 0x00 clen 4
      MTU 405
> ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Connect req: psm 25 scid 0x0042
< ACL data: handle 1 flags 0x02 dlen 18
    L2CAP(s): Config rsp: scid 0x0041 flags 0x00 result 0 clen 4
      MTU 405
< ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0041 flags 0x00 clen 4
      MTU 1013
< ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0042 scid 0x0042 result 1 status 1
      Connection pending - Authentication pending
< HCI Command: Authentication Requested (0x01|0x0011) plen 2
    handle 1
> HCI Event: Command Status (0x0f) plen 4
    Authentication Requested (0x01|0x0011) status 0x00 ncmd 1
> HCI Event: Link Key Request (0x17) plen 6
    bdaddr 00:17:E3:3B:4F:DD
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 2
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 18
    L2CAP(s): Config rsp: scid 0x0041 flags 0x00 result 0 clen 4
      MTU 1013
> ACL data: handle 1 flags 0x02 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 3]
      RFCOMM(s): SABM: cr 1 dlci 0 pf 1 ilen 0 fcs 0x1c
< ACL data: handle 1 flags 0x02 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 1 packets 1
< HCI Command: Link Key Request Negative Reply (0x01|0x000c) plen 6
    bdaddr 00:17:E3:3B:4F:DD
> HCI Event: Command Complete (0x0e) plen 10
    Link Key Request Negative Reply (0x01|0x000c) ncmd 1
    status 0x00 bdaddr 00:17:E3:3B:4F:DD
> HCI Event: PIN Code Request (0x16) plen 6
    bdaddr 00:17:E3:3B:4F:DD
> ACL data: handle 1 flags 0x02 dlen 18
    L2CAP(d): cid 0x0041 len 14 [psm 3]
      RFCOMM(s): PN CMD: cr 1 dlci 0 pf 0 ilen 10 fcs 0x70 mcc_len 8
      dlci 14 frame_type 0 credit_flow 15 pri 0 ack_timer 0
      frame_size 400 max_retrans 0 credits 0
< ACL data: handle 1 flags 0x02 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 14 frame_type 0 credit_flow 14 pri 0 ack_timer 0
      frame_size 400 max_retrans 0 credits 7
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 3]
      RFCOMM(s): SABM: cr 1 dlci 14 pf 1 ilen 0 fcs 0x6
< HCI Command: PIN Code Request Negative Reply (0x01|0x000e) plen 6
    bdaddr 00:17:E3:3B:4F:DD
> HCI Event: Command Complete (0x0e) plen 10
    PIN Code Request Negative Reply (0x01|0x000e) ncmd 1
    status 0x00 bdaddr 00:17:E3:3B:4F:DD
> HCI Event: Auth Complete (0x06) plen 3
    status 0x18 handle 1
    Error: Pairing Not Allowed
< ACL data: handle 1 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0042 scid 0x0042 result 3 status 0
      Connection refused - security block
< ACL data: handle 1 flags 0x02 dlen 8
    L2CAP(d): cid 0x0041 len 4 [psm 3]
      RFCOMM(s): DM: cr 1 dlci 14 pf 1 ilen 0 fcs 0x2c
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Disconn req: dcid 0x0041 scid 0x0041
< ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Disconn rsp: dcid 0x0041 scid 0x0041
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Disconn req: dcid 0x0040 scid 0x0040
< ACL data: handle 1 flags 0x02 dlen 12
    L2CAP(s): Disconn rsp: dcid 0x0040 scid 0x0040
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 1 packets 1
> HCI Event: Disconn Complete (0x05) plen 4
    status 0x00 handle 1 reason 0x13
    Reason: Remote User Terminated Connection
--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html


[Index of Archives]     [Bluez Devel]     [Linux Wireless Networking]     [Linux Wireless Personal Area Networking]     [Linux ATH6KL]     [Linux USB Devel]     [Linux Media Drivers]     [Linux Audio Users]     [Linux Kernel]     [Linux SCSI]     [Big List of Linux Books]

  Powered by Linux