Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

CONNECTION_REFUSED_PSM_NOT_SUPPORTED #428

Open
veaceslavgspot opened this issue Feb 21, 2024 · 2 comments
Open

CONNECTION_REFUSED_PSM_NOT_SUPPORTED #428

veaceslavgspot opened this issue Feb 21, 2024 · 2 comments

Comments

@veaceslavgspot
Copy link

I am trying to run the speaker example and connect to it from an emulator: python3 run_classic_discoverable.py speaker.json android-netsim.

The speaker appears in NetSim GUI and also it's discoverable in the emulator, but when attempting to pair with it connection seems to fail with CONNECTION_REFUSED_PSM_NOT_SUPPORTED. Any thoughts?

Emulators: Pixel 7 API 34 and Pixel 8 API 34.

Here the full log:

  bd_addr:         DA:4C:10:DE:17:00/P
  class_of_device: 5898764
  link_type:       ACL
DEBUG:bumble.device:*** Connection request: DA:4C:10:DE:17:00/P
DEBUG:bumble.host:### HOST -> CONTROLLER: HCI_ACCEPT_CONNECTION_REQUEST_COMMAND:
  bd_addr: DA:4C:10:DE:17:00/P
  role:    1
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_COMMAND_STATUS_EVENT:
  status:                  PENDING
  num_hci_command_packets: 1
  command_opcode:          HCI_ACCEPT_CONNECTION_REQUEST_COMMAND
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_CONNECTION_COMPLETE_EVENT:
  status:             HCI_SUCCESS
  connection_handle:  3838
  bd_addr:            DA:4C:10:DE:17:00/P
  link_type:          ACL
  encryption_enabled: 0
DEBUG:bumble.host:### BR/EDR CONNECTION: [0x0EFE] DA:4C:10:DE:17:00/P
DEBUG:bumble.device:*** Connection: [0x0EFE] DA:4C:10:DE:17:00/P
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=10, data=060001000a0202000200
DEBUG:bumble.hci:<<< ACL PDU: 060001000a0202000200
DEBUG:bumble.l2cap:<<< Received L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_INFORMATION_REQUEST [ID=2]:
  info_type: EXTENDED_FEATURES_SUPPORTED
DEBUG:bumble.l2cap:>>> Sending L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_INFORMATION_RESPONSE [ID=2]:
  info_type: EXTENDED_FEATURES_SUPPORTED
  result:    SUCCESS
  data:      80000000
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=1) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c0001000b0208000200000080000000
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c0001000b0208000200000080000000
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=10, data=060001000a0302000300
DEBUG:bumble.hci:<<< ACL PDU: 060001000a0302000300
DEBUG:bumble.l2cap:<<< Received L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_INFORMATION_REQUEST [ID=3]:
  info_type: FIXED_CHANNELS_SUPPORTED
DEBUG:bumble.l2cap:>>> Sending L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_INFORMATION_RESPONSE [ID=3]:
  info_type: FIXED_CHANNELS_SUPPORTED
  result:    SUCCESS
  data:      f200000000000000
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=1) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=20, data=100001000b030c0003000000f200000000000000
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=20, data=100001000b030c0003000000f200000000000000
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=12, data=080001000204040001004f00
DEBUG:bumble.hci:<<< ACL PDU: 080001000204040001004f00
DEBUG:bumble.l2cap:<<< Received L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONNECTION_REQUEST [ID=4]:
  psm:        1
  source_cid: 79
DEBUG:bumble.l2cap:creating server channel with cid=64 for psm 1
DEBUG:bumble.l2cap:Channel(64->79, PSM=1, MTU=2048/48, state=CLOSED) state change -> WAIT_CONNECT
DEBUG:bumble.l2cap:>>> Sending L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONNECTION_RESPONSE [ID=4]:
  destination_cid: 64
  source_cid:      79
  result:          CONNECTION_SUCCESSFUL
  status:          0
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=1) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c0001000304080040004f0000000000
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c0001000304080040004f0000000000
DEBUG:bumble.l2cap:Channel(64->79, PSM=1, MTU=2048/48, state=WAIT_CONNECT) state change -> WAIT_CONFIG
DEBUG:bumble.l2cap:>>> Sending L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONFIGURE_REQUEST [ID=1]:
  destination_cid: 79
  flags:           0
  options:         01020008
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=1) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c000100040108004f00000001020008
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c000100040108004f00000001020008
DEBUG:bumble.l2cap:Channel(64->79, PSM=1, MTU=2048/48, state=WAIT_CONFIG) state change -> WAIT_CONFIG_REQ_RSP
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=16, data=0c000100040508004000000001020004
DEBUG:bumble.hci:<<< ACL PDU: 0c000100040508004000000001020004
DEBUG:bumble.l2cap:<<< Received L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONFIGURE_REQUEST [ID=5]:
  destination_cid: 64
  flags:           0
  options:         01020004
DEBUG:bumble.l2cap:peer MTU = 1024
DEBUG:bumble.l2cap:>>> Sending L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONFIGURE_RESPONSE [ID=5]:
  source_cid: 79
  flags:      0
  result:     SUCCESS
  options:    01020004
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=1) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=18, data=0e00010005050a004f000000000001020004
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=18, data=0e00010005050a004f000000000001020004
DEBUG:bumble.l2cap:Channel(64->79, PSM=1, MTU=2048/1024, state=WAIT_CONFIG_REQ_RSP) state change -> WAIT_CONFIG_RSP
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=14, data=0a00010005010600400000000000
DEBUG:bumble.hci:<<< ACL PDU: 0a00010005010600400000000000
DEBUG:bumble.l2cap:<<< Received L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONFIGURE_RESPONSE [ID=1]:
  source_cid: 64
  flags:      0
  result:     SUCCESS
  options:
DEBUG:bumble.l2cap:Channel(64->79, PSM=1, MTU=2048/1024, state=WAIT_CONFIG_RSP) state change -> OPEN
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=28, data=180040000600000013350319110b03f0350909000109000409000900
DEBUG:bumble.hci:<<< ACL PDU: 180040000600000013350319110b03f0350909000109000409000900
DEBUG:bumble.sdp:<<< Received SDP Request: SDP_SERVICE_SEARCH_ATTRIBUTE_REQUEST [TID=0]:
  service_search_pattern:       SEQUENCE([UUID(UUID-16:110B (AudioSink))])
  maximum_attribute_byte_count: 1008
  attribute_id_list:            SEQUENCE([UNSIGNED_INTEGER(1#2),UNSIGNED_INTEGER(4#2),UNSIGNED_INTEGER(9#2)])
  continuation_state:           00
DEBUG:bumble.sdp:Search response: SEQUENCE([SEQUENCE([UNSIGNED_INTEGER(1#2),SEQUENCE([UUID(UUID-16:110B (AudioSink))]),UNSIGNED_INTEGER(4#2),SEQUENCE([SEQUENCE([UUID(UUID-16:0100 (L2CAP)),UNSIGNED_INTEGER(25#2)]),SEQUENCE([UUID(UUID-16:0019 (AVDTP)),UNSIGNED_INTEGER(256#2)])]),UNSIGNED_INTEGER(9#2),SEQUENCE([SEQUENCE([UUID(UUID-16:110D (AdvancedAudioDistribution)),UNSIGNED_INTEGER(256#2)])])])])
DEBUG:bumble.sdp:>>> Sending SDP Response: SDP_SERVICE_SEARCH_ATTRIBUTE_RESPONSE [TID=0]:
  attribute_lists_byte_count: 46
  attribute_lists:            SEQUENCE([SEQUENCE([UNSIGNED_INTEGER(1#2),SEQUENCE([UUID(UUID-16:110B (AudioSink))]),UNSIGNED_INTEGER(4#2),SEQUENCE([SEQUENCE([UUID(UUID-16:0100 (L2CAP)),UNSIGNED_INTEGER(25#2)]),SEQUENCE([UUID(UUID-16:0019 (AVDTP)),UNSIGNED_INTEGER(256#2)])]),UNSIGNED_INTEGER(9#2),SEQUENCE([SEQUENCE([UUID(UUID-16:110D (AdvancedAudioDistribution)),UNSIGNED_INTEGER(256#2)])])])])
  continuation_state:         00
DEBUG:bumble.l2cap:>>> Sending L2CAP PDU on connection [0x0EFE] (CID=79) DA:4C:10:DE:17:00/P: 54 bytes, SDP_SERVICE_SEARCH_ATTRIBUTE_RESPONSE [TID=0]:
  attribute_lists_byte_count: 46
  attribute_lists:            SEQUENCE([SEQUENCE([UNSIGNED_INTEGER(1#2),SEQUENCE([UUID(UUID-16:110B (AudioSink))]),UNSIGNED_INTEGER(4#2),SEQUENCE([SEQUENCE([UUID(UUID-16:0100 (L2CAP)),UNSIGNED_INTEGER(25#2)]),SEQUENCE([UUID(UUID-16:0019 (AVDTP)),UNSIGNED_INTEGER(256#2)])]),UNSIGNED_INTEGER(9#2),SEQUENCE([SEQUENCE([UUID(UUID-16:110D (AdvancedAudioDistribution)),UNSIGNED_INTEGER(256#2)])])])])
  continuation_state:         00
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=79) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=58, data=36004f000700000031002e352c352a090001350319110b0900043510350619010009001935061900190901000900093508350619110d09010000
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=58, data=36004f000700000031002e352c352a090001350319110b0900043510350619010009001935061900190901000900093508350619110d09010000
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=12, data=080001000606040040004f00
DEBUG:bumble.hci:<<< ACL PDU: 080001000606040040004f00
DEBUG:bumble.l2cap:<<< Received L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_DISCONNECTION_REQUEST [ID=6]:
  destination_cid: 64
  source_cid:      79
DEBUG:bumble.l2cap:>>> Sending L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_DISCONNECTION_RESPONSE [ID=6]:
  destination_cid: 64
  source_cid:      79
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=1) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=12, data=080001000706040040004f00
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=12, data=080001000706040040004f00
DEBUG:bumble.l2cap:Channel(64->79, PSM=1, MTU=2048/1024, state=OPEN) state change -> CLOSED
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_ENCRYPTION_CHANGE_EVENT:
  status:             HCI_SUCCESS
  connection_handle:  3838
  encryption_enabled: AES_CCM
DEBUG:bumble.device:*** Connection Encryption Change: [0x0EFE] DA:4C:10:DE:17:00/P as PERIPHERAL, encryption=2
DEBUG:bumble.host:### CONTROLLER -> HOST: ACL: handle=0x0efe, pb=2, bc=0, data_total_length=12, data=080001000207040019005000
DEBUG:bumble.hci:<<< ACL PDU: 080001000207040019005000
DEBUG:bumble.l2cap:<<< Received L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONNECTION_REQUEST [ID=7]:
  psm:        25
  source_cid: 80
WARNING:bumble.l2cap:No server for connection 0x0EFE on PSM 25
DEBUG:bumble.l2cap:>>> Sending L2CAP Signaling Control Frame on connection [0x0EFE] (CID=1) DA:4C:10:DE:17:00/P:
L2CAP_CONNECTION_RESPONSE [ID=7]:
  destination_cid: 80
  source_cid:      0
  result:          CONNECTION_REFUSED_PSM_NOT_SUPPORTED
  status:          0
DEBUG:bumble.host:>>> ACL packet enqueue: (CID=1) ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c000100030708005000000002000000
DEBUG:bumble.host:### HOST -> CONTROLLER: ACL: handle=0x0efe, pb=0, bc=0, data_total_length=16, data=0c000100030708005000000002000000
DEBUG:bumble.host:### CONTROLLER -> HOST: HCI_NUMBER_OF_COMPLETED_PACKETS_EVENT:
  number_of_handles:        1
  connection_handle[0]:     3838
  num_completed_packets[0]: 1
@zxzxwu
Copy link
Collaborator

zxzxwu commented Feb 21, 2024

run_classic_discoverable.py only provides a fake SDP record, and there is no corresponding profile for it. To run speaker example, I suggest you to use apps/speaker.

https://github.com/google/bumble/blob/main/apps/speaker/speaker.py

@barbibulle
Copy link
Collaborator

NOTE: you will also see CONNECTION_REFUSED_PSM_NOT_SUPPORTED when running the speaker app with Android as the client. This is perfectly normal: the speaker app doesn't (yet) implement AVRCP (remote control), which is a service on PSM 23. Somehow Android insists on connecting to AVRCP even though it's not advertised in the SDP. But that should not block anything else.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@barbibulle @zxzxwu @veaceslavgspot