Audio application - No valid advertising data stored

[muli]

Hi all. I am using the latest nrf5340_audio application from NCS v2.5.1 running on nRF5340 Audio DK boards

From time to time, the application crashes with the below errors. Any idea what is wrong here, and how to possibly solve it? Thanks

HL [00:01:46.099,029] <inf> broadcast_sink: Stream index 0 started
HL [00:01:46.099,060] <inf> broadcast_sink: Codec config for LC3:
HL [00:01:46.099,060] <inf> broadcast_sink:     Frequency: 48000 Hz
HL [00:01:46.099,060] <inf> broadcast_sink:     Frame Duration: 10000 us
HL [00:01:46.099,060] <inf> broadcast_sink:     Octets per frame: 120 (96000 kbps)
HL [00:01:46.099,090] <inf> broadcast_sink:     Frames per SDU: 1
HL [00:01:46.099,090] <inf> broadcast_sink:     Channel allocation: 0x1
HL [00:01:46.490,539] <inf> bt_mgmt: Disconnected: 4D:42:B3:3B:7D:E1 (random) (reason 0x08)
HL [00:01:46.490,570] <wrn> streamctrl_broadcast_sink: Unexpected/unhandled bt_mgmt event: 6
HL [00:01:46.490,570] <err> bt_mgmt_adv: No valid advertising data stored
HL [00:01:46.490,600] <err> bt_mgmt: ERR_CHK Err_code: [-2] @ line: 177
HL [00:01:46.490,600] <err> os: r0/a1:  0x00000003  r1/a2:  0x0000000b  r2/a3:  0x0000000a
HL [00:01:46.490,600] <err> os: r3/a4:  0x000699e5 r12/ip:  0x0000000c r14/lr:  0x00069a6f
HL [00:01:46.490,600] <err> os:  xpsr:  0x41100000
HL [00:01:46.490,631] <err> os: s[ 0]:  0x00000000  s[ 1]:  0x00000010  s[ 2]:  0x20019720  s[ 3]:  0x00079a54
HL [00:01:46.490,631] <err> os: s[ 4]:  0x20019728  s[ 5]:  0x00000000  s[ 6]:  0x00000000  s[ 7]:  0x00000000
HL [00:01:46.490,631] <err> os: s[ 8]:  0x00000000  s[ 9]:  0x0000968b  s[10]:  0x00006d6f  s[11]:  0x200038d8
HL [00:01:46.490,661] <err> os: s[12]:  0x00000002  s[13]:  0x200038d8  s[14]:  0x00000002  s[15]:  0x20019720
HL [00:01:46.490,661] <err> os: fpscr:  0x00000004
HL [00:01:46.490,661] <err> os: Faulting instruction address (r15/pc): 0x00009698
HL [00:01:46.490,692] <err> os: >>> ZEPHYR FATAL ERROR 3: Kernel oops on CPU 0
HL [00:01:46.490,692] <err> os: Current thread: 0x20004838 (sysworkq)
HL [00:01:46.490,722] <err> error_handler: Caught system error -- reason 3. Entering infinite loop

Just now, I had another crash, even when not switching streams.

HL [00:08:20.906,555] <wrn> audio_datapath: In I2S TX underrun condition, total: 425000
HL [00:08:25.906,585] <wrn> audio_datapath: In I2S TX underrun condition, total: 430000
HL [00:08:30.906,585] <wrn> audio_datapath: In I2S TX underrun condition, total: 435000
HL [00:08:35.906,616] <wrn> audio_datapath: In I2S TX underrun condition, total: 440000
HL [00:08:40.906,616] <wrn> audio_datapath: In I2S TX underrun condition, total: 445000
HL [00:08:45.906,646] <wrn> audio_datapath: In I2S TX underrun condition, total: 450000
HL [00:08:50.906,646] <wrn> audio_datapath: In I2S TX underrun condition, total: 455000
HL [00:08:55.906,677] <wrn> audio_datapath: In I2S TX underrun condition, total: 460000
HL [00:09:00.906,677] <wrn> audio_datapath: In I2S TX underrun condition, total: 465000
HL [00:09:05.906,707] <wrn> audio_datapath: In I2S TX underrun condition, total: 470000
HL [00:09:10.906,707] <wrn> audio_datapath: In I2S TX underrun condition, total: 475000
HL [00:09:15.906,738] <wrn> audio_datapath: In I2S TX underrun condition, total: 480000
HL [00:09:20.906,768] <wrn> audio_datapath: In I2S TX underrun condition, total: 485000
HL [00:09:25.906,768] <wrn> audio_datapath: In I2S TX underrun condition, total: 490000
HL [00:09:30.906,799] <wrn> audio_datapath: In I2S TX underrun condition, total: 495000
HL [00:09:35.906,799] <wrn> audio_datapath: In I2S TX underrun condition, total: 500000
HL [00:09:40.906,829] <wrn> audio_datapath: In I2S TX underrun condition, total: 505000
HL [00:09:45.906,829] <wrn> audio_datapath: In I2S TX underrun condition, total: 510000
HL [00:09:48.736,663] <inf> bt_mgmt: Disconnected: 68:24:8C:26:BC:6A (random) (reason 0x08)
HL [00:09:48.736,694] <wrn> streamctrl_broadcast_sink: Unexpected/unhandled bt_mgmt event: 6
HL [00:09:48.736,694] <err> bt_mgmt_adv: No valid advertising data stored
HL [00:09:48.736,694] <err> bt_mgmt: ERR_CHK Err_code: [-2] @ line: 177
HL [00:09:48.736,724] <err> os: r0/a1:  0x00000003  r1/a2:  0x00000004  r2/a3:  0x00000003
HL [00:09:48.736,724] <err> os: r3/a4:  0x00069df1 r12/ip:  0x0000000c r14/lr:  0x00069e7b
HL [00:09:48.736,724] <err> os:  xpsr:  0x41100000
HL [00:09:48.736,755] <err> os: s[ 0]:  0x00000000  s[ 1]:  0x00000010  s[ 2]:  0x20019720  s[ 3]:  0x00079e64
HL [00:09:48.736,755] <err> os: s[ 4]:  0x20019728  s[ 5]:  0x00000000  s[ 6]:  0x00000000  s[ 7]:  0x00000000
HL [00:09:48.736,755] <err> os: s[ 8]:  0x00000000  s[ 9]:  0x0000968b  s[10]:  0x00006d6f  s[11]:  0x200038d8
HL [00:09:48.736,785] <err> os: s[12]:  0x00000002  s[13]:  0x200038d8  s[14]:  0x00000002  s[15]:  0x20019720
HL [00:09:48.736,785] <err> os: fpscr:  0x00000004
HL [00:09:48.736,785] <err> os: Faulting instruction address (r15/pc): 0x00009698
HL [00:09:48.736,816] <err> os: >>> ZEPHYR FATAL ERROR 3: Kernel oops on CPU 0
HL [00:09:48.736,816] <err> os: Current thread: 0x20004838 (sysworkq)
HL [00:09:48.736,846] <err> error_handler: Caught system error -- reason 3. Entering infinite loop

[ovrebekk]

Hi Paul

I assume you have made some changes to the example?
If so, can you provide a summary of the changes you have made?

How close is the "not switching streams" scenario to the standard LE Audio application? 

Would you say the issue is easy to reproduce, or does it happen very intermittently? 

Best regards
Torbjørn

[muli]

Hi ovrebekk 

Yes I made a few changes. The receiver application now also advertises and allows a Bluetooth connection from a Central device. The Central can then send messages to the receiver via NUS which tells it which broadcast source and stream to listen to. 

With the standard LE Audio application, button 4 switches the audio stream from right to left channel. I also reproduced the issue doing just this. 

However, yesterday out of nowhere when the audio stream was just playing for a while, without switching, I got the crash in the second log report above. I'm not sure how to interpret the errors. 

Thanks

[ovrebekk]

Hi Paul

I got some input from the developers which I have shared below: 

It seems you are trying to add an ACL connection to the BIS headset sample, but there are some missing pieces: 

1) According to the error log sent from the bt_mgmt_evt_handler in streamctrl_broadcast_sink.c from here, you have unhandled event 6, which corresponds with BT_MGMT_DISCONNECTED. You need to handle this event here.  

2) The BT_MGMT_DISCONNETED event is sent from this line.

3) The ADV error is similar in nature, and is generated here.

4) If you look into bt_mgmt_adv_start() here you can see that various input parameters are required, some of which might not be set correctly in your case.   

A general tip is to have a look at how this is handled in unicast_server.c, in combination with the connection handling that is done by the bt_mgmt module. 

Hopefully this will get you a bit further along. If something is still unclear let me know, and I will do my best to help. 

Best regards
Torbjørn

[muli]

ovrebekk Thanks so much for looking into this. 

Now it's becoming more obvious as to what is wrong.

In fact bt_mgmt_adv_start() doesn't get called from streamctrl_start() in the audio application if the device is a receiver. As you mention, it's not designed by default to advertise and have a connection. 

I should be able to solve it now. 

Best regards,

Paul

[ovrebekk]

Hi Paul

Glad to hear I was able to help out

I will consider the case resolved then. The best of luck with your project!

Best regards
Torbjørn