Missing configuration for network core for ISO_Connected_Benchmark.

tsmp 9 months ago

Hi everyone, I am attempting to configure two of NRF5340DK modules to execute ISO_Connected_Benchmark.

I have tried to configure ipc_radio to compile for cpunet and application seems to run initially. I have used kconfig from another example application for that. Also, i have managed to cobble together ipc_radio that at least attempts to connect.

On execution i get:

Choose device role - type c (central role) or p (peripheral role), or q to quit: c
Central role
Change ISO settings (y/N)?
[00:01:07.586,303] <inf> iso_connected: Creating CIG
[00:01:07.588,897] <inf> iso_connected: Scan started
[00:01:07.588,897] <inf> iso_connected: Waiting for advertiser
[00:01:07.606,323] <inf> iso_connected: Found peripheral with address E4:83:AA:0D:8F:BB (random) (RSSI -28)
[00:01:07.606,353] <inf> iso_connected: Stopping scan
[00:01:07.611,358] <inf> iso_connected: Scan stopped
[00:01:07.611,358] <inf> iso_connected: Connecting
[00:01:07.641,876] <inf> iso_connected: Connected: E4:83:AA:0D:8F:BB (random)
[00:01:07.641,998] <inf> iso_connected: Connecting ISO channels
[00:01:10.643,249] <inf> iso_connected: Disconnected: E4:83:AA:0D:8F:BB (random), reason 0x13
[00:01:10.645,416] <wrn> bt_hci_core: opcode 0x206f status 0x0c
[00:01:10.645,935] <wrn> bt_hci_core: opcode 0x206f status 0x0c
[00:01:10.645,965] <inf> iso_connected: ISO Channel 0x200008e8 disconnected with reason 0x13 after 0 milliseconds (average duration 0)

Choose device role - type c (central role) or p (peripheral role), or q to quit: p
Peripheral role
[00:00:10.312,561] <inf> iso_connected: Registering ISO server
[00:00:10.312,561] <inf> iso_connected: Starting advertising
[00:00:10.314,971] <inf> iso_connected: Waiting for ACL connection
[00:00:19.098,327] <inf> iso_connected: Connected: DC:BD:16:AA:41:7D (random)
[00:00:19.098,449] <inf> iso_connected: Waiting for ISO connection
[00:00:21.100,006] <inf> iso_connected: Incoming ISO request from 0x20001778
[00:00:21.100,036] <inf> iso_connected: Returning instance 0
[00:00:22.099,578] <inf> iso_connected: Disconnected: DC:BD:16:AA:41:7D (random), reason 0x16 
[00:00:22.099,639] <inf> iso_connected: Test complete: -11

I will attach my WIP conf file. Sysbuild file that i had to add is not allowed on this forum, so i won't attach it.
ipc_radio.conf

I am still learning but i would be happy to know how to diagnose that issue and how to solve my problem.

Parents

0 Kenneth 9 months ago

Hi,

Don't have an nRF5340DK I can try myself, but I think that the problem may be related to some missing configuration of the controller running on the network core of the nRF5340. Maybe make sure that you have the configuration placed in \iso_connected_benchmark\sysbuild\ipc_radio\prj.conf

Kenneth
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Reply

0 Kenneth 9 months ago

Hi,

Don't have an nRF5340DK I can try myself, but I think that the problem may be related to some missing configuration of the controller running on the network core of the nRF5340. Maybe make sure that you have the configuration placed in \iso_connected_benchmark\sysbuild\ipc_radio\prj.conf

Kenneth
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Children

0 tsmp 9 months ago in reply to Kenneth

I see no reason to put the config in that folder. Your courses suggest ipc_radio.conf as correct config name. Build system also seems to ignore subfolder variant for me. I know though, that I can go select configuration trough build domain in NRF Connect SDK. I have decided to configure my project from scratch and I found several logging options. I am attaching updated logs.

Central role
Change ISO settings (y/N)?
[00:02:34.119,934] <inf> iso_connected: Creating CIG
--- 4 messages dropped ---
[00:02:34.120,086] <dbg> bt_iso: hci_le_set_cig_params: [0]: id 0, c_phy 2, c_sdu 247, c_rtn 2, p_phy 2, p_sdu 247, p_rtn 2
--- 24 messages dropped ---
[00:02:34.121,002] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2062 len 5
--- 12 messages dropped ---
[00:02:34.121,459] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:34.121,459] <dbg> bt_conn: bt_conn_tx_processor: start
[00:02:34.121,490] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:02:34.121,704] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0e 04 01 05 20 00                             |..... .          
--- 102 messages dropped ---
[00:02:34.189,941] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 12
[00:02:34.190,002] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x2000915c)
[00:02:34.190,002] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x2000915c len 14
--- 67 messages dropped ---
[00:02:34.198,425] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
--- 32 messages dropped ---
[00:02:34.198,455] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:34.198,486] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:34.198,486] <dbg> bt_conn: bt_conn_tx_processor: start
[00:02:34.198,516] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:02:34.198,547] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:02:34.198,577] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x200d len 0
[00:02:34.225,769] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 3e 13 01 00 00 00 00  01 7d 41 aa 16 bd dc 90 |.>...... .}A.....
                                        01 00 00 90 01 00                                |......           
[00:02:34.225,769] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 19
[00:02:34.225,799] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x20008d70)
[00:02:34.225,830] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20008d70 len 21
[00:02:34.225,860] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:02:34.225,891] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 21
[00:02:34.225,891] <dbg> bt_hci_core: hci_event: event 0x3e
[00:02:34.225,921] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x01
[00:02:34.226,074] <dbg> bt_hci_core: le_legacy_conn_complete: status 0x00 BT_HCI_ERR_SUCCESS role 0 DC:BD:16:AA:41:7D (random)
[00:02:34.226,348] <dbg> bt_hci_core: bt_hci_le_enh_conn_complete: status 0x00 BT_HCI_ERR_SUCCESS handle 0 role 0 peer DC:BD:16:AA:41:7D (random) peer RPA 00:00:00:00:00:00
[00:02:34.226,440] <dbg> bt_hci_core: bt_hci_le_enh_conn_complete: local RPA 00:00:00:00:00:00
[00:02:34.226,470] <dbg> bt_conn: bt_conn_ref: handle 0 ref 2 -> 3
[00:02:34.226,501] <dbg> bt_conn: bt_conn_set_state: initiating -> connected
[00:02:34.226,531] <dbg> bt_conn: schedule_auto_initiated_procedures: [0x20001f98] Scheduling auto-init procedures
[00:02:34.226,562] <dbg> bt_l2cap: l2cap_accept: conn 0x20001f98 handle 0
[00:02:34.226,593] <dbg> bt_l2cap: bt_l2cap_chan_add: conn 0x20001f98 chan 0x20002d48
[00:02:34.226,623] <dbg> bt_l2cap: l2cap_connected: ch 0x20002d48 cid 0x0005
[00:02:34.226,623] <dbg> bt_smp: bt_smp_accept: conn 0x20001f98 handle 0
[00:02:34.226,654] <dbg> bt_l2cap: bt_l2cap_chan_add: conn 0x20001f98 chan 0x20002e2c
[00:02:34.226,654] <dbg> bt_att: bt_att_accept: conn 0x20001f98 handle 0
[00:02:34.226,715] <dbg> bt_att: att_chan_attach: att 0x20009fe8 chan 0x20005c40 flags 0
[00:02:34.226,745] <dbg> bt_l2cap: bt_l2cap_chan_add: conn 0x20001f98 chan 0x20005c44
[00:02:34.226,745] <dbg> bt_att: bt_att_connected: chan 0x20005c44 cid 0x0004
[00:02:34.226,776] <dbg> bt_gatt: bt_gatt_connected: conn 0x20001f98
[00:02:34.226,806] <dbg> bt_att: bt_att_status: chan 0x20005c44 status 0x20005c54
[00:02:34.226,928] <inf> iso_connected: Connected: DC:BD:16:AA:41:7D (random)
[00:02:34.226,959] <dbg> bt_conn: bt_conn_unref: handle 0 ref 3 -> 2
[00:02:34.227,020] <dbg> bt_conn: bt_conn_ref: handle 0 ref 2 -> 3
[00:02:34.227,050] <dbg> bt_conn: perform_auto_initiated_procedures: [0x20001f98] Running auto-initiated procedures
[00:02:34.227,050] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2016 param_len 2
[00:02:34.227,081] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:02:34.227,111] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2016 len 5
[00:02:34.227,142] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:34.227,142] <dbg> bt_hci_core: bt_hci_cmd_send_sync: process cmd 0x20009cf0 want 0x20009cf0
[00:02:34.227,172] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:02:34.227,203] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2016 (buf 0x20009cf0) to driver
[00:02:34.227,203] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 5 type 1
[00:02:34.227,233] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 5
[00:02:34.227,264] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 16 20 02 00 00                                |.. ...           
[00:02:34.227,355] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        00 00 00 00 33 30 02 00  b4 92 00 20 2e 46 02 00 |....30.. ... .F..
                                        00 19                                            |..               
[00:02:34.227,386] <inf> iso_connected: Connecting ISO channels
[00:02:34.227,416] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2064 param_len 5
[00:02:34.227,447] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009d0c
[00:02:34.227,447] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009d0c opcode 0x2064 len 8
[00:02:34.227,478] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:34.227,569] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0f 04 00 01 16 20                             |......           
[00:02:34.227,600] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:02:34.227,630] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:02:34.227,661] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:02:34.227,661] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2016
[00:02:34.227,752] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2016 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:02:34.227,783] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:02:34.227,813] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:34.227,844] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2016 len 0
[00:02:34.227,874] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2032 param_len 7
[00:02:34.227,905] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:02:34.227,935] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2032 len 10
[00:02:34.227,935] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:34.227,966] <dbg> bt_hci_core: bt_hci_cmd_send_sync: process cmd 0x20009d0c want 0x20009cf0
[00:02:34.227,996] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:02:34.227,996] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2064 (buf 0x20009d0c) to driver
[00:02:34.228,027] <dbg> bt_hci_core: bt_send: buf 0x20009d0c len 8 type 1
[00:02:34.228,057] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009d0c type 1 len 8
[00:02:34.228,088] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 64 20 05 01 03 00 00  00                      |.d ..... .       
[00:02:34.228,118] <dbg> bt_hci_core: bt_hci_cmd_send_sync: process cmd 0x20009cf0 want 0x20009cf0
[00:02:34.228,179] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:02:34.228,515] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0f 04 00 01 64 20                             |.....d           
[00:02:34.228,546] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:02:34.228,576] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:02:34.228,607] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:02:34.228,607] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2064
[00:02:34.228,698] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2064 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:02:34.228,729] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:02:34.228,790] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:34.228,820] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:02:34.228,851] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2032 (buf 0x20009cf0) to driver
[00:02:34.228,851] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 10 type 1
[00:02:34.228,881] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 10
[00:02:34.228,912] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 32 20 07 00 00 00 02  02 00 00                |.2 ..... ...     
[00:02:34.228,973] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:02:34.229,034] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009d0c opcode 0x2064 len 0
[00:02:34.229,064] <dbg> bt_conn: bt_conn_ref: handle 0 ref 3 -> 4
[00:02:34.229,095] <dbg> bt_conn: bt_conn_set_state: disconnected -> initiating
[00:02:34.229,217] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0f 04 00 01 32 20                             |.....2           
[00:02:34.229,248] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:02:34.229,278] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:02:34.229,309] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:02:34.229,309] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2032
[00:02:34.229,400] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2032 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:02:34.229,431] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:02:34.229,461] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:34.229,492] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2032 len 0
[00:02:34.229,522] <dbg> bt_conn: perform_auto_initiated_procedures: [0x20001f98] Successfully ran auto-initiated procedures
[00:02:34.229,553] <dbg> bt_conn: bt_conn_unref: handle 0 ref 4 -> 3
[00:02:34.229,553] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:34.229,583] <dbg> bt_conn: bt_conn_tx_processor: start
[00:02:34.229,614] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:02:34.229,644] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:02:36.227,386] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 3e 0c 04 00 00 00 0d  49 00 f7 01 01 00 00    |.>...... I...... 
[00:02:36.227,416] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 12
[00:02:36.227,447] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x20008d70)
[00:02:36.227,478] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20008d70 len 14
[00:02:36.227,508] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:02:36.227,508] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 14
[00:02:36.227,508] <dbg> bt_hci_core: hci_event: event 0x3e
[00:02:36.227,539] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x04
[00:02:36.227,539] <dbg> bt_conn: bt_conn_ref: handle 0 ref 3 -> 4
[00:02:36.227,569] <dbg> bt_conn: bt_conn_unref: handle 0 ref 4 -> 3
[00:02:36.227,630] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        04 47 02 00 5c 91 00 20  0e 00 00                |.G..\..  ...     
[00:02:37.727,081] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 05 04 00 00 00 13                             |.......          
--- 7 messages dropped ---
[00:02:37.727,294] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.727,325] <dbg> bt_conn: bt_conn_unref: handle 0 ref 4 -> 3
[00:02:37.727,355] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:02:37.727,386] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 6
[00:02:37.727,386] <dbg> bt_hci_core: hci_event: event 0x05
[00:02:37.727,447] <dbg> bt_hci_core: hci_disconn_complete: status 0x00 BT_HCI_ERR_SUCCESS handle 0 reason 0x13
[00:02:37.727,478] <dbg> bt_conn: bt_conn_ref: handle 0 ref 3 -> 4
[00:02:37.727,508] <dbg> bt_conn: bt_conn_set_state: disconnect-complete -> disconnected
[00:02:37.727,539] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:37.727,539] <dbg> bt_conn: bt_conn_tx_processor: start
[00:02:37.727,569] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:02:37.727,569] <dbg> bt_conn: tx_notify_process: conn 0x20001f98
[00:02:37.727,600] <dbg> bt_conn: bt_conn_set_state: trigger disconnect work
[00:02:37.727,600] <dbg> bt_conn: bt_conn_unref: handle 0 ref 4 -> 3
[00:02:37.727,661] <dbg> bt_conn: deferred_work: conn 0x20001f98
[00:02:37.727,661] <dbg> bt_conn: bt_conn_ref: handle 3 ref 1 -> 2
[00:02:37.727,661] <dbg> bt_iso: bt_iso_cleanup_acl: 0x20002150
[00:02:37.727,691] <dbg> bt_conn: bt_conn_unref: handle 0 ref 3 -> 2
[00:02:37.727,691] <dbg> bt_conn: bt_conn_unref: handle 3 ref 2 -> 1
[00:02:37.727,722] <dbg> bt_conn: bt_conn_ref: handle 3 ref 1 -> 2
[00:02:37.727,722] <dbg> bt_conn: bt_conn_unref: handle 3 ref 2 -> 1
[00:02:37.727,722] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001f98 chan 0x20002d48
[00:02:37.727,752] <dbg> bt_l2cap: cancel_data_ready: 0x20002d48
[00:02:37.727,752] <dbg> bt_l2cap: l2cap_disconnected: ch 0x20002d48 cid 0x0005
[00:02:37.727,783] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001f98 chan 0x20002e2c
[00:02:37.727,783] <dbg> bt_l2cap: cancel_data_ready: 0x20002e2c
[00:02:37.727,783] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001f98 chan 0x20005c44
[00:02:37.727,813] <dbg> bt_l2cap: cancel_data_ready: 0x20005c44
[00:02:37.727,813] <dbg> bt_att: bt_att_disconnected: chan 0x20005c44 cid 0x0004
[00:02:37.727,844] <dbg> bt_att: att_chan_detach: chan 0x20005c40
[00:02:37.727,844] <dbg> bt_gatt: bt_gatt_disconnected: conn 0x20001f98
[00:02:37.727,874] <dbg> bt_att: bt_att_released: chan 0x20005c40
[00:02:37.728,027] <inf> iso_connected: Disconnected: DC:BD:16:AA:41:7D (random), reason 0x13 BT_HCI_ERR_REMOTE_USER_TERM_CONN
[00:02:37.728,057] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1
[00:02:37.728,057] <dbg> bt_conn: bt_conn_unref: handle 0 ref 1 -> 0
[00:02:37.728,118] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        b1 48 02 00                                      |.H..             
[00:02:37.728,912] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 3e 2b 2a 13 03 00 0d  49 00 bc 12 00 00 00 00 |.>+*.... I.......
                                        00 00 00 00 00 02 00 00  00 00 00 90 01 00 00 90 |........ ........
                                        01 00 ff ff ff 70 75 74  e8 51 ea 53 b9 b9       |.....put .Q.S..  
[00:02:37.728,912] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 43
[00:02:37.728,942] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x20008d70)
[00:02:37.728,942] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20008d70 len 45
[00:02:37.728,973] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:02:37.729,003] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 45
[00:02:37.729,003] <dbg> bt_hci_core: hci_event: event 0x3e
[00:02:37.729,034] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x2a
[00:02:37.729,095] <dbg> bt_iso: hci_le_cis_established_v2: status 0x13 BT_HCI_ERR_REMOTE_USER_TERM_CONN handle 3
[00:02:37.729,095] <dbg> bt_conn: bt_conn_ref: handle 3 ref 1 -> 2
[00:02:37.729,125] <dbg> bt_iso: bt_iso_disconnected: 0x20002150
[00:02:37.729,125] <dbg> bt_iso: bt_iso_chan_disconnected: 0x20000908, reason 0x13
[00:02:37.729,156] <dbg> bt_conn: bt_conn_set_state: initiating -> disconnect-complete
[00:02:37.729,187] <dbg> bt_conn: process_unack_tx: 0x20002150
[00:02:37.729,187] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.729,217] <dbg> bt_iso: bt_iso_cleanup_acl: 0x20002150
[00:02:37.729,217] <dbg> bt_iso: bt_iso_remove_data_path: 0x20002150
[00:02:37.729,217] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x206f param_len 3
[00:02:37.729,248] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:02:37.729,278] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x206f len 6
[00:02:37.729,278] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.729,309] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:37.729,339] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:02:37.729,339] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x206f (buf 0x20009cf0) to driver
[00:02:37.729,370] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 6 type 1
[00:02:37.729,370] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 6
[00:02:37.729,400] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 6f 20 03 03 00 01                             |.o ....          
[00:02:37.729,431] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.729,461] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:37.729,461] <dbg> bt_conn: bt_conn_tx_processor: start
[00:02:37.729,492] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:02:37.729,522] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        13 03 00 0d 49 00 bc 12  00 00 00 00 00 00 00 00 |....I... ........
                                        00 02 00 00 00 00 00 90  01 00 00 90 01 00 ff ff |........ ........
                                        ff 70 75 74 e8 51 ea 53  b9 b9                   |.put.Q.S ..      
[00:02:37.729,705] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0e 06 01 6f 20 0c 03  00                      |....o .. .       
[00:02:37.729,705] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 6
[00:02:37.729,736] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:02:37.729,736] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 8
[00:02:37.729,766] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x206f
[00:02:37.729,827] <dbg> bt_hci_core: hci_cmd_done: opcode 0x206f status 0x0c BT_HCI_ERR_CMD_DISALLOWED buf 0x200092b4
[00:02:37.729,858] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:02:37.729,888] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.729,980] <wrn> bt_hci_core: opcode 0x206f status 0x0c BT_HCI_ERR_CMD_DISALLOWED
[00:02:37.730,010] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x206f param_len 3
[00:02:37.730,010] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:02:37.730,041] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x206f len 6
[00:02:37.730,041] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.730,072] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:37.730,102] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:02:37.730,102] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x206f (buf 0x20009cf0) to driver
[00:02:37.730,133] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 6 type 1
[00:02:37.730,133] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 6
[00:02:37.730,163] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 6f 20 03 03 00 02                             |.o ....          
[00:02:37.730,194] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.730,224] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:37.730,224] <dbg> bt_conn: bt_conn_tx_processor: start
[00:02:37.730,255] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:02:37.730,285] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        1d 1d 4e                                         |..N              
[00:02:37.730,468] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0e 06 01 6f 20 0c 03  00                      |....o .. .       
[00:02:37.730,468] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 6
[00:02:37.730,499] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:02:37.730,499] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 8
[00:02:37.730,529] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x206f
[00:02:37.730,590] <dbg> bt_hci_core: hci_cmd_done: opcode 0x206f status 0x0c BT_HCI_ERR_CMD_DISALLOWED buf 0x200092b4
[00:02:37.730,621] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:02:37.730,651] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:02:37.730,743] <wrn> bt_hci_core: opcode 0x206f status 0x0c BT_HCI_ERR_CMD_DISALLOWED
[00:02:37.730,804] <inf> iso_connected: ISO Channel 0x20000908 disconnected with reason 0x13 after 0 milliseconds (average duration 0)
[00:02:37.730,804] <dbg> bt_conn: bt_conn_unref: handle 3 ref 2 -> 1
[00:02:37.730,865] <dbg> bt_hci_core: tx_processor: TX process start
[00:02:37.730,865] <dbg> bt_conn: bt_conn_tx_processor: start
[00:02:37.730,895] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:02:37.730,926] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        00 21 00                                         |.!.

Peripheral role
--- 5 messages dropped ---
[00:00:57.133,453] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:00:57.133,483] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2006 len 18
[00:00:57.133,483] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.133,544] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.133,544] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:00:57.133,544] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2006 (buf 0x20009cf0) to driver
[00:00:57.133,575] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 18 type 1
[00:00:57.133,575] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 18
[00:00:57.133,605] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 06 20 0f 30 00 60 00  00 01 00 00 00 00 00 00 |.. .0.`. ........
                                        00 07 00                                         |...              
[00:00:57.133,636] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.133,666] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.133,666] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.133,697] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.133,972] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0e 04 01 06 20 00                             |..... .          
[00:00:57.133,972] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:00:57.134,002] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:00:57.134,002] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:00:57.134,033] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x2006
[00:00:57.134,094] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2006 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:00:57.134,124] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:00:57.134,155] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.134,185] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.134,185] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.134,216] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.134,246] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        03                                               |.                
[00:00:57.134,277] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2006 len 1
[00:00:57.134,307] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2008 param_len 32
[00:00:57.134,307] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:00:57.134,338] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2008 len 35
[00:00:57.134,338] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.134,368] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.134,399] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:00:57.134,399] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2008 (buf 0x20009cf0) to driver
[00:00:57.134,399] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 35 type 1
[00:00:57.134,429] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 35
[00:00:57.134,460] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 08 20 20 00 00 00 00  00 00 00 00 00 00 00 00 |..  .... ........
                                        00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 |........ ........
                                        00 00 00 00                                      |....             
[00:00:57.134,490] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.134,490] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.134,521] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.134,521] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.134,765] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0e 04 01 08 20 00                             |..... .          
[00:00:57.134,796] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:00:57.134,796] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:00:57.134,826] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:00:57.134,826] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x2008
[00:00:57.134,918] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2008 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:00:57.134,918] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:00:57.134,948] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.134,979] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.135,009] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.135,009] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.135,040] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        02                                               |.                
[00:00:57.135,070] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2008 len 1
[00:00:57.135,101] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2009 param_len 32
[00:00:57.135,131] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:00:57.135,131] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2009 len 35
[00:00:57.135,162] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.135,192] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.135,192] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:00:57.135,192] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2009 (buf 0x20009cf0) to driver
[00:00:57.135,223] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 35 type 1
[00:00:57.135,223] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 35
[00:00:57.135,253] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 09 20 20 1a 19 09 49  53 4f 20 43 6f 6e 6e 65 |..  ...I SO Conne
                                        63 74 65 64 20 54 68 72  6f 75 67 68 70 75 74 00 |cted Thr oughput.
                                        00 00 00 00                                      |....             
[00:00:57.135,284] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.135,314] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.135,314] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.135,345] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.135,589] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0e 04 01 09 20 00                             |..... .          
[00:00:57.135,589] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:00:57.135,620] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:00:57.135,620] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:00:57.135,650] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x2009
[00:00:57.135,711] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2009 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:00:57.135,742] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:00:57.135,772] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.135,803] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.135,803] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.135,803] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.135,864] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        13                                               |.                
[00:00:57.135,894] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2009 len 1
[00:00:57.135,955] <dbg> bt_conn: bt_conn_set_state: disconnected -> adv-connectable
[00:00:57.135,986] <dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2
[00:00:57.135,986] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1
[00:00:57.136,016] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:00:57.136,016] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x200a len 4
[00:00:57.136,047] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.136,047] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.136,077] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:00:57.136,077] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x200a (buf 0x20009cf0) to driver
[00:00:57.136,108] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 4 type 1
[00:00:57.136,108] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 4
[00:00:57.136,138] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 0a 20 01 01                                   |.. ..            
[00:00:57.136,169] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.136,199] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.136,199] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.136,199] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.136,566] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0e 04 01 0a 20 00                             |..... .          
[00:00:57.136,596] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:00:57.136,596] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:00:57.136,627] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:00:57.136,627] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x200a
[00:00:57.136,718] <dbg> bt_hci_core: hci_cmd_done: opcode 0x200a status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:00:57.136,718] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:00:57.136,749] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:57.136,779] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:57.136,810] <dbg> bt_conn: bt_conn_tx_processor: start
[00:00:57.136,810] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:00:57.136,871] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        10                                               |.                
[00:00:57.136,901] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x200a len 1
[00:00:57.136,932] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1
[00:00:57.136,962] <inf> iso_connected: Waiting for ACL connection
[00:01:04.072,998] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 3e 13 01 00 02 00 01  01 bb 8f 0d aa 83 e4 90 |.>...... ........
                                        01 00 00 90 01 05                                |......           
[00:01:04.073,028] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 19
[00:01:04.073,059] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x20008d70)
[00:01:04.073,089] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20008d70 len 21
[00:01:04.073,089] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:01:04.073,120] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 21
[00:01:04.073,120] <dbg> bt_hci_core: hci_event: event 0x3e
[00:01:04.073,150] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x01
[00:01:04.073,303] <dbg> bt_hci_core: le_legacy_conn_complete: status 0x00 BT_HCI_ERR_SUCCESS role 1 E4:83:AA:0D:8F:BB (random)
[00:01:04.073,516] <dbg> bt_hci_core: bt_hci_le_enh_conn_complete: status 0x00 BT_HCI_ERR_SUCCESS handle 2 role 1 peer E4:83:AA:0D:8F:BB (random) peer RPA 00:00:00:00:00:00
[00:01:04.073,638] <dbg> bt_hci_core: bt_hci_le_enh_conn_complete: local RPA 00:00:00:00:00:00
[00:01:04.073,638] <dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2
[00:01:04.073,669] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1
[00:01:04.073,669] <dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2
[00:01:04.073,699] <dbg> bt_conn: bt_conn_set_state: adv-connectable -> connected
[00:01:04.073,730] <dbg> bt_conn: schedule_auto_initiated_procedures: [0x20001f98] Scheduling auto-init procedures
[00:01:04.073,760] <dbg> bt_l2cap: l2cap_accept: conn 0x20001f98 handle 2
[00:01:04.073,760] <dbg> bt_l2cap: bt_l2cap_chan_add: conn 0x20001f98 chan 0x20002d48
[00:01:04.073,791] <dbg> bt_l2cap: l2cap_connected: ch 0x20002d48 cid 0x0005
[00:01:04.073,791] <dbg> bt_smp: bt_smp_accept: conn 0x20001f98 handle 2
[00:01:04.073,822] <dbg> bt_l2cap: bt_l2cap_chan_add: conn 0x20001f98 chan 0x20002e2c
[00:01:04.073,822] <dbg> bt_att: bt_att_accept: conn 0x20001f98 handle 2
[00:01:04.073,852] <dbg> bt_att: att_chan_attach: att 0x20009fe8 chan 0x20005c40 flags 0
[00:01:04.073,883] <dbg> bt_l2cap: bt_l2cap_chan_add: conn 0x20001f98 chan 0x20005c44
[00:01:04.073,883] <dbg> bt_att: bt_att_connected: chan 0x20005c44 cid 0x0004
[00:01:04.073,913] <dbg> bt_gatt: bt_gatt_connected: conn 0x20001f98
[00:01:04.073,944] <dbg> bt_att: bt_att_status: chan 0x20005c44 status 0x20005c54
[00:01:04.074,005] <dbg> bt_conn: bt_conn_ref: handle 2 ref 2 -> 3
[00:01:04.074,066] <inf> iso_connected: Connected: E4:83:AA:0D:8F:BB (random)
[00:01:04.074,066] <dbg> bt_conn: bt_conn_unref: handle 2 ref 3 -> 2
[00:01:04.074,096] <dbg> bt_conn: bt_conn_ref: handle 2 ref 2 -> 3
[00:01:04.074,127] <dbg> bt_conn: perform_auto_initiated_procedures: [0x20001f98] Running auto-initiated procedures
[00:01:04.074,127] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2016 param_len 2
[00:01:04.074,157] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:01:04.074,157] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2016 len 5
[00:01:04.074,188] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:04.074,218] <dbg> bt_hci_core: bt_hci_cmd_send_sync: process cmd 0x20009cf0 want 0x20009cf0
[00:01:04.074,218] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:01:04.074,218] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2016 (buf 0x20009cf0) to driver
[00:01:04.074,249] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 5 type 1
[00:01:04.074,249] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 5
[00:01:04.074,279] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 16 20 02 02 00                                |.. ...           
[00:01:04.074,340] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        03 00 00 00 d9 3f 02 00  53 46 02 00 50 0f 02 00 |.....?.. SF..P...
                                        00 19                                            |..               
[00:01:04.074,371] <inf> iso_connected: Waiting for ISO connection
[00:01:04.074,645] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0f 04 00 01 16 20                             |......           
[00:01:04.074,645] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:01:04.074,676] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:01:04.074,707] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:01:04.074,707] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2016
[00:01:04.074,798] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2016 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:01:04.074,798] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:01:04.074,829] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:04.074,859] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2016 len 0
[00:01:04.074,859] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2032 param_len 7
[00:01:04.074,890] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:01:04.074,890] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2032 len 10
[00:01:04.074,920] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:04.074,920] <dbg> bt_hci_core: bt_hci_cmd_send_sync: process cmd 0x20009cf0 want 0x20009cf0
[00:01:04.074,951] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:01:04.074,951] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2032 (buf 0x20009cf0) to driver
[00:01:04.074,981] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 10 type 1
[00:01:04.074,981] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 10
[00:01:04.075,012] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 32 20 07 02 00 00 02  02 00 00                |.2 ..... ...     
[00:01:04.075,073] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:01:04.075,317] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0f 04 00 01 32 20                             |.....2           
[00:01:04.075,347] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:01:04.075,347] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:01:04.075,378] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:01:04.075,378] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2032
[00:01:04.075,469] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2032 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:01:04.075,469] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:01:04.075,500] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:04.075,531] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2032 len 0
[00:01:04.075,531] <dbg> bt_conn: perform_auto_initiated_procedures: [0x20001f98] Successfully ran auto-initiated procedures
[00:01:04.075,561] <dbg> bt_conn: bt_conn_unref: handle 2 ref 3 -> 2
[00:01:04.075,561] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:04.075,592] <dbg> bt_conn: bt_conn_tx_processor: start
[00:01:04.075,592] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:01:04.075,622] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:01:05.574,645] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 3e 0c 04 00 02 00 0d  49 00 f7 01 01 00 00    |.>...... I...... 
[00:01:05.574,676] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 12
[00:01:05.574,707] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x20008d70)
[00:01:05.574,707] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20008d70 len 14
[00:01:05.574,737] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:01:05.574,737] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 14
[00:01:05.574,768] <dbg> bt_hci_core: hci_event: event 0x3e
[00:01:05.574,768] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x04
[00:01:05.574,798] <dbg> bt_conn: bt_conn_ref: handle 2 ref 2 -> 3
[00:01:05.574,798] <dbg> bt_conn: bt_conn_unref: handle 2 ref 3 -> 2
[00:01:05.574,859] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        2d 58 02 00 00 00 00 00  00 21 70                |-X...... .!p     
[00:01:06.074,432] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x0406 param_len 3
[00:01:06.074,462] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:01:06.074,493] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x0406 len 6
[00:01:06.074,493] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:06.074,523] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:06.074,554] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:01:06.074,554] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x0406 (buf 0x20009cf0) to driver
[00:01:06.074,554] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 6 type 1
[00:01:06.074,584] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 6
[00:01:06.074,615] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 06 04 03 02 00 13                             |.......          
[00:01:06.074,645] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:06.074,676] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:06.074,707] <dbg> bt_conn: bt_conn_tx_processor: start
[00:01:06.074,707] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:01:06.074,920] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0f 04 00 01 06 04                             |.......          
[00:01:06.074,951] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:01:06.074,981] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:01:06.074,981] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:01:06.075,012] <dbg> bt_hci_core: hci_cmd_status: opcode 0x0406
[00:01:06.075,073] <dbg> bt_hci_core: hci_cmd_done: opcode 0x0406 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:01:06.075,103] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:01:06.075,103] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:06.075,134] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:06.075,164] <dbg> bt_conn: bt_conn_tx_processor: start
[00:01:06.075,164] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:01:06.075,195] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:01:06.075,225] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x0406 len 0
[00:01:06.075,256] <dbg> bt_conn: bt_conn_set_state: connected -> disconnecting
[00:01:06.574,920] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 3e 07 1a 02 00 03 00  00 00                   |.>...... ..      
[00:01:06.574,951] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 7
[00:01:06.574,981] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x20008d70)
[00:01:06.575,012] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20008d70 len 9
[00:01:06.575,042] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:01:06.575,042] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 9
[00:01:06.575,042] <dbg> bt_hci_core: hci_event: event 0x3e
[00:01:06.575,073] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x1a
[00:01:06.575,073] <dbg> bt_iso: hci_le_cis_req: acl_handle 2 cis_handle 3 cig_id 0 cis 0
[00:01:06.575,103] <dbg> bt_conn: bt_conn_ref: handle 2 ref 2 -> 3
[00:01:06.575,134] <dbg> bt_conn: bt_conn_unref: handle 2 ref 3 -> 2
[00:01:06.575,134] <dbg> bt_conn: bt_conn_ref: handle 2 ref 2 -> 3
[00:01:06.575,195] <dbg> bt_conn: bt_conn_ref: handle 2 ref 3 -> 4
[00:01:06.575,195] <dbg> bt_conn: bt_conn_unref: handle 2 ref 4 -> 3
[00:01:06.575,225] <dbg> bt_iso: iso_accept: 0x20002150
[00:01:06.575,225] <inf> iso_connected: Incoming ISO request from 0x20001f98
[00:01:06.575,225] <inf> iso_connected: Returning instance 0
[00:01:06.575,256] <dbg> bt_iso: bt_iso_chan_add: iso 0x20002150 chan 0x20000908
[00:01:06.575,286] <dbg> bt_conn: bt_conn_set_state: disconnected -> initiating
[00:01:06.575,286] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2066 param_len 2
[00:01:06.575,317] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20009cf0
[00:01:06.575,317] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20009cf0 opcode 0x2066 len 5
[00:01:06.575,347] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:06.575,378] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:06.575,378] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:01:06.575,408] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x2066 (buf 0x20009cf0) to driver
[00:01:06.575,408] <dbg> bt_hci_core: bt_send: buf 0x20009cf0 len 5 type 1
[00:01:06.575,439] <dbg> bt_hci_driver: bt_ipc_send: buf 0x20009cf0 type 1 len 5
[00:01:06.575,439] <dbg> bt_hci_driver: bt_ipc_send: Final HCI buffer:
                                        01 66 20 02 03 00                                |.f ...           
[00:01:06.575,500] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:06.575,500] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:06.575,531] <dbg> bt_conn: bt_conn_tx_processor: start
[00:01:06.575,531] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:01:06.575,561] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        02 00 03 00 00 00                                |......           
[00:01:06.575,744] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 0f 04 00 01 66 20                             |.....f           
[00:01:06.575,775] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:01:06.575,805] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x200092b4)
[00:01:06.575,805] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x200092b4 len 6
[00:01:06.575,836] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2066
[00:01:06.575,897] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2066 status 0x00 BT_HCI_ERR_SUCCESS buf 0x200092b4
[00:01:06.575,927] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:01:06.575,927] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:06.575,958] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20009cf0 opcode 0x2066 len 0
[00:01:06.576,019] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:06.576,019] <dbg> bt_conn: bt_conn_tx_processor: start
[00:01:06.576,019] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:01:06.576,049] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
[00:01:07.574,371] <dbg> bt_hci_driver: bt_ipc_rx: ipc data:
                                        04 05 04 00 02 00 16                             |.......          
[00:01:07.574,401] <dbg> bt_hci_driver: bt_ipc_evt_recv: len 4
[00:01:07.574,401] <dbg> bt_hci_driver: bt_ipc_rx: Calling bt_recv(0x20008d70)
[00:01:07.574,432] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20008d70 len 6
[00:01:07.574,493] <dbg> bt_hci_core: hci_disconn_complete_prio: status 0x00 BT_HCI_ERR_SUCCESS handle 2 reason 0x16
[00:01:07.574,523] <dbg> bt_conn: bt_conn_ref: handle 2 ref 3 -> 4
[00:01:07.574,554] <dbg> bt_conn: bt_conn_set_state: disconnecting -> disconnect-complete
[00:01:07.574,554] <dbg> bt_conn: process_unack_tx: 0x20001f98
[00:01:07.574,554] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:01:07.574,584] <dbg> bt_conn: bt_conn_unref: handle 2 ref 4 -> 3
[00:01:07.574,615] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
[00:01:07.574,645] <dbg> bt_hci_core: rx_work_handler: buf 0x20008d70 type 2 len 6
[00:01:07.574,645] <dbg> bt_hci_core: hci_event: event 0x05
[00:01:07.574,707] <dbg> bt_hci_core: hci_disconn_complete: status 0x00 BT_HCI_ERR_SUCCESS handle 2 reason 0x16
[00:01:07.574,737] <dbg> bt_conn: bt_conn_ref: handle 2 ref 3 -> 4
[00:01:07.574,768] <dbg> bt_conn: bt_conn_set_state: disconnect-complete -> disconnected
[00:01:07.574,798] <dbg> bt_hci_core: tx_processor: TX process start
[00:01:07.574,829] <dbg> bt_conn: bt_conn_tx_processor: start
[00:01:07.574,829] <dbg> bt_conn: bt_conn_tx_processor: no connection wants to do stuff
[00:01:07.574,859] <dbg> bt_conn: tx_notify_process: conn 0x20001f98
[00:01:07.574,859] <dbg> bt_conn: bt_conn_set_state: trigger disconnect work
[00:01:07.574,890] <dbg> bt_conn: bt_conn_unref: handle 2 ref 4 -> 3
[00:01:07.574,920] <dbg> bt_conn: deferred_work: conn 0x20001f98
[00:01:07.574,951] <dbg> bt_conn: bt_conn_ref: handle 3 ref 1 -> 2
[00:01:07.574,951] <dbg> bt_iso: bt_iso_cleanup_acl: 0x20002150
[00:01:07.574,951] <dbg> bt_conn: bt_conn_unref: handle 2 ref 3 -> 2
[00:01:07.574,981] <dbg> bt_conn: bt_conn_unref: handle 3 ref 2 -> 1
[00:01:07.574,981] <dbg> bt_conn: bt_conn_ref: handle 3 ref 1 -> 2
[00:01:07.575,012] <dbg> bt_conn: bt_conn_unref: handle 3 ref 2 -> 1
[00:01:07.575,012] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001f98 chan 0x20002d48
[00:01:07.575,012] <dbg> bt_l2cap: cancel_data_ready: 0x20002d48
[00:01:07.575,042] <dbg> bt_l2cap: l2cap_disconnected: ch 0x20002d48 cid 0x0005
[00:01:07.575,042] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001f98 chan 0x20002e2c
[00:01:07.575,073] <dbg> bt_l2cap: cancel_data_ready: 0x20002e2c
[00:01:07.575,073] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001f98 chan 0x20005c44
[00:01:07.575,073] <dbg> bt_l2cap: cancel_data_ready: 0x20005c44
[00:01:07.575,103] <dbg> bt_att: bt_att_disconnected: chan 0x20005c44 cid 0x0004
[00:01:07.575,103] <dbg> bt_att: att_chan_detach: chan 0x20005c40
[00:01:07.575,134] <dbg> bt_gatt: bt_gatt_disconnected: conn 0x20001f98
[00:01:07.575,164] <dbg> bt_att: bt_att_released: chan 0x20005c40
[00:01:07.575,317] <inf> iso_connected: Disconnected: E4:83:AA:0D:8F:BB (random), reason 0x16 BT_HCI_ERR_LOCALHOST_TERM_CONN
[00:01:07.575,317] <dbg> bt_conn: bt_conn_unref: handle 2 ref 2 -> 1
[00:01:07.575,347] <dbg> bt_conn: bt_conn_unref: handle 2 ref 1 -> 0
[00:01:07.575,408] <dbg> bt_hci_driver: bt_ipc_rx: RX buf payload:
                                        06 00 00 00                                      |....             
[00:01:07.575,408] <inf> iso_connected: Test complete: -11
Choose device role - type c (central role) or p (peripheral role), or q to quit:

I have tried several combinations. On top of 3.0.3 SDK with IPC_RADIO i have also tried 3.0.99 (i had checked out Zephyr@63febf7715f and NRF@a7917f813) with IPC_RADIO and HCI_IPC. Curiously, HCI and IPC versions behave slightly differently. On HCI Net App seems to crash with unresponsive controller assertion. Curiously, offending opcodes seemed to change a bit run to run. I recall at least 0x2022, 0x2032, 0x2064 among others.

IPC version seems to just hang trying to take sem_iso_connected. Application never goes into iso_connected callback, so it is not supprising, that application waits idefinitely.

All versions fail in some way in bt_iso_chan_connect.

Judging from that 3.0.99 and 3.0.3 sdk versions of that project are slightly different and NRF5340DK and NRF5340_AUDIO_DK are default boards i have high hopes, that in span of last few months there was someone at Nordic that had that project running on my platform.

I am also attaching my futile attempts at making that application work.

3099_ipc.zip

303_ipc.zip

3099_hci.zip

0 Kenneth 9 months ago in reply to tsmp

It might be the example is currently broken, I will report it so it can be looked into. It might be worth a try with v2.9.2 if you have time.

Kenneth
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 tsmp 9 months ago in reply to Kenneth

It definitely was worth a try. It worked first try on my devkits. I am even quite positive, that I still had 3.0.99 netapp on my device.

Thank you for help!
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel