Panic, when playing music

I have build a sample project nRF5430_audio for nRF5340 Auido DK(two DK, one for gateway, one for headset), following the guide:nRF5340 Audio — nRF Connect SDK 2.0.99 documentation (nordicsemi.com)

build the project:

python buildprog.py -c both -b debug -d both -p

add following to prj.conf
CONFIG_SW_CODEC_SBC=y
CONFIG_AUDIO_SOURCE_USB=y
CONFIG_TRANSPORT_CIS=y

after streaming for a while,the headset will panic:
HL [00:08:42.849,517] <wrn> audio_datapath: Invalid sdu_ref_us delta (9983) - Estimating sdu_ref_us 
HL [00:08:44.309,600] <wrn> audio_datapath: Invalid sdu_ref_us delta (9983) - Estimating sdu_ref_us 
HL [00:08:53.321,838] <wrn> sw_codec_select: PCM samples dropped 
HL [00:08:53.321,868] <err> audio_datapath: Decoded audio has wrong size 
HL [00:08:53.321,868] <err> audio_datapath: ERR_CHK Err_code: [-140] @ line: 815 
HL [00:08:53.321,868] <err> os: r0/a1: 0x00000003 r1/a2: 0x00000003 r2/a3: 0x00000002 
HL [00:08:53.321,899] <err> os: r3/a4: 0x20001e10 r12/ip: 0x00000002 r14/lr: 0x00017b85 
HL [00:08:53.321,899] <err> os: xpsr: 0x41000000 
HL [00:08:53.321,899] <err> os: s[ 0]: 0x00000000 s[ 1]: 0x00000000 s[ 2]: 0x00000000 s[ 3]: 0x00000000 
HL [00:08:53.321,899] <err> os: s[ 4]: 0x00000000 s[ 5]: 0x00000000 s[ 6]: 0x00000000 s[ 7]: 0x00000000 
HL [00:08:53.321,929] <err> os: s[ 8]: 0x00000000 s[ 9]: 0x00000000 s[10]: 0x00000000 s[11]: 0x00000000 
HL [00:08:53.321,929] <err> os: s[12]: 0x00000000 s[13]: 0x00000000 s[14]: 0x00000000 s[15]: 0xffffffff 
HL [00:08:53.321,929] <err> os: fpscr: 0x200002f0 
HL [00:08:53.321,960] <err> os: Faulting instruction address (r15/pc): 0x0000651c 
HL [00:08:53.321,960] <err> os: >>> ZEPHYR FATAL ERROR 3: Kernel oops on CPU 0 
HL [00:08:53.321,960] <err> os: Current thread: 0x20001688 (AUDIO DATAPATH) 
HL [00:08:53.321,960] <err> error_handler: Caught system error -- reason 3. Entering infinite loop 

so, i think there is a bug, is any patch for it?

thanks

Top Replies

Karl Ylvisaker over 4 years ago in reply to Zhongsan +1 verified

Thank you for the update - I am glad to see that you were able to test for 8 hours continuously with so few bad frames / issues. Please do not hesitate to open a new ticket if you should encounter any…

Parents

0 Karl Ylvisaker over 4 years ago

Hello,

It seems that the data received is reported as the wrong size, which causes the operation to cancel.
Have you made any other changes to the reference application than those you have listed at the beginning of your ticket?

I notice that you are using the SBC codec, could you confirm that you have also removed the following:

CONFIG_LC3_ENC_CHAN_MAX=2
CONFIG_LC3_DEC_CHAN_MAX=1

from overlay-headset.conf and overlay-gateway.conf?

As a side note I would also like to recommend that you use the LC3 codec for your evaluation if possible, since it significantly outperforms the SBC in all aspects for the common audio use-cases.

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Zhongsan over 4 years ago in reply to Karl Ylvisaker

Hi

i am sure i have remove that from both overlay-headset.conf and overlay-gateway.conf

thanks
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Zhongsan over 4 years ago in reply to Karl Ylvisaker

Hi, Karl

after more than 8 hours of test, we got the following message:

$ *** Booting Zephyr OS build v3.0.99-ncs1-rc1 ***
HL [00:00:00.362,426] <dbg> nrf5340_audio_dk_nrf5340_cpuapp: core_config: Setting gpiote latency to r
HL [00:00:00.362,487] <dbg> nrf5340_audio_dk_nrf5340_cpuapp: remoteproc_mgr_boot: Network MCU releas.
HL [00:00:00.367,034] <dbg> main: main: nRF5340 APP core started
HL [00:00:00.367,614] <inf> fw_info:
nRF5340 Audio nRF5340 Audio DK cpuapp
FW Version: 0.5.99
Cmake run : Mon Jun 13 23:53:01 2022
HL [00:00:00.367,614] <inf> fw_info: ------- DEBUG BUILD -------
HL [00:00:00.367,645] <inf> fw_info:
HEADSET left device
HL [00:00:00.378,234] <dbg> board_version: version_search: Board ver search OK!. ADC reg val: 1760
HL [00:00:00.378,234] <inf> board_version: Compatible board/HW version found: 1.0.0
HL [00:00:00.388,824] <dbg> board_version: version_search: Board ver search OK!. ADC reg val: 1774
HL [00:00:00.408,569] <inf> CS47L63: Tried to set supply, not supported
HL [00:00:00.429,321] <dbg> HW_CODEC: cs47l63_comm_reg_conf_write: Busy waiting instead of writing t3
HL [00:00:00.442,474] <wrn> bt_hci_core: Controller to host flow control not supported
HL [00:00:00.445,281] <dbg> ble: on_bt_ready: Bluetooth initialized
HL [00:00:00.571,197] <inf> ble: MAC: E1:28:5F:33:30:0E (random)
HL [00:00:00.571,411] <inf> ble: Controller version: 3251
HL [00:00:00.639,007] <dbg> HW_CODEC: cs47l63_comm_reg_conf_write: Busy waiting instead of writing t3
HL [00:00:00.640,899] <dbg> ble: iso_bis_rx_sync_get: Start scanning...
HL [00:00:00.642,517] <dbg> ble: iso_bis_rx_sync_get: Waiting for periodic advertising...
HL [00:00:00.649,505] <wrn> audio_datapath: I2S RX overrun. Single msg
HL [00:00:22.733,581] <inf> ble: Stop scanning...
HL [00:00:22.733,947] <dbg> ble: iso_bis_rx_sync_get: Creating Periodic Advertising Sync...
HL [00:00:22.735,870] <dbg> ble: iso_bis_rx_sync_get: Waiting for periodic sync
HL [00:00:22.975,860] <dbg> ble: iso_bis_rx_sync_get: Periodic sync established
HL [00:00:23.255,676] <dbg> ble: ble_trans_iso_init: Init finished
HL [00:00:23.255,767] <dbg> audio_datapath: audio_datapath_tone_play: Tone started
HL [00:00:23.255,798] <dbg> streamctrl: m_ble_transport_evt_handler: Received event = 0, current sta0
HL [00:00:23.255,798] <inf> streamctrl: BLE evt connected
HL [00:00:23.255,798] <dbg> streamctrl: m_ble_transport_evt_handler: Received event = 2, current sta1
HL [00:00:23.255,798] <inf> streamctrl: BLE evt link ready
HL [00:00:23.755,828] <dbg> audio_datapath: tone_stop_worker: Tone stopped
HL [00:00:41.946,838] <dbg> streamctrl: m_button_evt_handler: Got btn evt from queue - id = 4, actio0
HL [00:00:41.946,868] <dbg> ble: iso_bis_rx_sync_get: Already have sync, returning
HL [00:00:41.946,868] <dbg> ble: iso_bis_rx_start: Trying to get sync...
HL [00:00:42.017,181] <dbg> ble: iso_connected_cb: ISO Channel 0x20008f94 connected
HL [00:00:42.017,272] <dbg> ble: iso_bis_rx_start: bt_iso_big_sync established
HL [00:00:42.017,303] <dbg> streamctrl: m_button_evt_handler: Starting headset device
HL [00:00:42.017,303] <dbg> streamctrl: m_ble_transport_evt_handler: Received event = 3, current sta3
HL [00:00:42.017,303] <inf> streamctrl: BLE evt streaming
HL [00:00:42.018,981] <inf> audio_datapath: Drft comp state: CALIB
HL [00:00:42.019,958] <wrn> audio_datapath: Data received, total underruns: 2
HL [00:00:42.080,963] <wrn> audio_datapath: Data received, total underruns: 3
HL [00:00:42.118,957] <inf> audio_datapath: Drft comp state: OFFSET
HL [00:00:42.539,550] <inf> audio_datapath: Drft comp state: LOCKED
HL [00:00:42.548,370] <inf> audio_datapath: Pres comp state: MEAS
HL [00:00:42.658,355] <inf> audio_datapath: Pres comp state: WAIT
HL [00:00:42.658,386] <dbg> audio_datapath: audio_datapath_presentation_compensation: Presentation d6
HL [00:00:42.718,383] <inf> audio_datapath: Pres comp state: INIT
HL [00:00:42.729,278] <inf> audio_datapath: Pres comp state: MEAS
HL [00:00:42.838,378] <inf> audio_datapath: Pres comp state: LOCKED
HL [00:00:56.211,059] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [00:00:56.211,120] <wrn> sw_codec_select: PCM samples dropped
HL [00:00:56.211,120] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [00:16:03.624,053] <inf> audio_datapath: sdu_ref_us not from consecutive frames
HL [00:16:03.624,084] <inf> audio_datapath: Pres comp state: WAIT
HL [00:16:03.625,213] <wrn> audio_datapath: Data received, total underruns: 16
HL [00:16:03.674,072] <inf> audio_datapath: Pres comp state: INIT
HL [00:16:03.684,051] <inf> audio_datapath: Pres comp state: MEAS
HL [00:16:03.794,067] <inf> audio_datapath: Pres comp state: WAIT
HL [00:16:03.794,097] <dbg> audio_datapath: audio_datapath_presentation_compensation: Presentation d7
HL [00:16:03.854,064] <inf> audio_datapath: Pres comp state: INIT
HL [00:16:03.864,074] <inf> audio_datapath: Pres comp state: MEAS
HL [00:16:03.974,090] <inf> audio_datapath: Pres comp state: LOCKED
HL [00:38:08.592,712] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [00:38:08.592,773] <wrn> sw_codec_select: PCM samples dropped
HL [00:38:08.592,773] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [00:38:59.018,371] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [00:38:59.018,432] <wrn> sw_codec_select: PCM samples dropped
HL [00:38:59.018,432] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [00:59:01.947,601] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [00:59:01.947,662] <wrn> sw_codec_select: PCM samples dropped
HL [00:59:01.947,662] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [01:30:39.962,249] <wrn> audio_datapath: In I2S TX underrun condition, total: 5000
.....
HL [02:04:10.084,564] <wrn> audio_datapath: In I2S TX underrun condition, total: 2015000
HL [02:04:11.089,080] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [02:04:11.089,080] <inf> audio_datapath: sdu_ref_us not from consecutive frames
HL [02:04:11.089,111] <inf> audio_datapath: Pres comp state: WAIT
HL [02:04:11.089,141] <wrn> sw_codec_select: PCM samples dropped
HL [02:04:11.089,172] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [02:04:11.089,630] <wrn> audio_datapath: Data received, total underruns: 2016004
HL [02:04:11.184,661] <inf> audio_datapath: Drft comp state: OFFSET
HL [02:04:11.483,428] <inf> audio_datapath: Drft comp state: LOCKED
HL [02:04:15.094,573] <wrn> audio_datapath: In I2S TX underrun condition, total: 2020000
.....
HL [02:25:15.171,630] <wrn> audio_datapath: In I2S TX underrun condition, total: 3280000
HL [02:25:17.520,812] <inf> audio_datapath: sdu_ref_us not from consecutive frames
HL [02:25:17.521,789] <wrn> audio_datapath: Data received, total underruns: 3282349
HL [02:25:17.560,791] <inf> audio_datapath: Drft comp state: OFFSET
HL [02:25:17.560,852] <inf> audio_datapath: Pres comp state: INIT
HL [02:25:17.858,978] <inf> audio_datapath: Drft comp state: LOCKED
HL [02:25:17.860,809] <inf> audio_datapath: Pres comp state: MEAS
HL [02:25:17.970,825] <inf> audio_datapath: Pres comp state: WAIT
HL [02:25:17.970,825] <dbg> audio_datapath: audio_datapath_presentation_compensation: Presentation d7
HL [02:25:18.030,822] <inf> audio_datapath: Pres comp state: INIT
HL [02:25:18.040,832] <inf> audio_datapath: Pres comp state: MEAS
HL [02:25:18.150,817] <inf> audio_datapath: Pres comp state: LOCKED
HL [02:46:37.444,976] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [02:46:37.445,037] <wrn> sw_codec_select: PCM samples dropped
HL [02:46:37.445,037] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [03:32:09.018,737] <inf> audio_datapath: sdu_ref_us not from consecutive frames
HL [03:32:09.018,737] <inf> audio_datapath: Pres comp state: WAIT
HL [03:32:09.019,897] <wrn> audio_datapath: Data received, total underruns: 3282632
HL [03:32:09.068,725] <inf> audio_datapath: Pres comp state: INIT
HL [03:32:09.078,735] <inf> audio_datapath: Pres comp state: MEAS
HL [03:32:09.188,751] <inf> audio_datapath: Pres comp state: WAIT
HL [03:32:09.188,751] <dbg> audio_datapath: audio_datapath_presentation_compensation: Presentation d7
HL [03:32:09.248,748] <inf> audio_datapath: Pres comp state: INIT
HL [03:32:09.258,728] <inf> audio_datapath: Pres comp state: MEAS
HL [03:32:09.368,743] <inf> audio_datapath: Pres comp state: LOCKED
HL [03:39:28.005,126] <inf> audio_datapath: sdu_ref_us not from consecutive frames
HL [03:39:28.005,157] <inf> audio_datapath: Pres comp state: WAIT
HL [03:39:28.006,317] <wrn> audio_datapath: Data received, total underruns: 3282765
HL [03:39:28.055,145] <inf> audio_datapath: Pres comp state: INIT
HL [03:39:28.065,155] <inf> audio_datapath: Pres comp state: MEAS
HL [03:39:28.175,140] <inf> audio_datapath: Pres comp state: WAIT
HL [03:39:28.175,170] <dbg> audio_datapath: audio_datapath_presentation_compensation: Presentation d7
HL [03:39:28.235,168] <inf> audio_datapath: Pres comp state: INIT
HL [03:39:28.245,178] <inf> audio_datapath: Pres comp state: MEAS
HL [03:39:28.355,163] <inf> audio_datapath: Pres comp state: LOCKED
HL [03:46:18.599,792] <inf> audio_datapath: sdu_ref_us not from consecutive frames
HL [03:46:18.599,822] <inf> audio_datapath: Pres comp state: WAIT
HL [03:46:18.600,952] <wrn> audio_datapath: Data received, total underruns: 3282798
HL [03:46:18.649,810] <inf> audio_datapath: Pres comp state: INIT
HL [03:46:18.659,790] <inf> audio_datapath: Pres comp state: MEAS
HL [03:46:18.769,805] <inf> audio_datapath: Pres comp state: WAIT
HL [03:46:18.769,805] <dbg> audio_datapath: audio_datapath_presentation_compensation: Presentation d7
HL [03:46:18.829,803] <inf> audio_datapath: Pres comp state: INIT
HL [03:46:18.839,813] <inf> audio_datapath: Pres comp state: MEAS
HL [03:46:18.949,829] <inf> audio_datapath: Pres comp state: LOCKED
HL [04:01:11.272,827] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [04:01:11.272,888] <wrn> sw_codec_select: PCM samples dropped
HL [04:01:11.272,888] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [04:55:04.378,692] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [04:55:04.378,753] <wrn> sw_codec_select: PCM samples dropped
HL [04:55:04.378,753] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [04:55:04.828,735] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [04:55:04.828,796] <wrn> sw_codec_select: PCM samples dropped
HL [04:55:04.828,796] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [04:55:05.388,732] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [04:55:05.388,763] <wrn> sw_codec_select: PCM samples dropped
HL [04:55:05.388,793] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [04:55:06.148,773] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [04:55:06.148,834] <wrn> sw_codec_select: PCM samples dropped
HL [04:55:06.148,834] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [04:55:10.209,075] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [04:55:10.209,136] <wrn> sw_codec_select: PCM samples dropped
HL [04:55:10.209,136] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [06:40:45.324,523] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [06:40:45.324,584] <wrn> sw_codec_select: PCM samples dropped
HL [06:40:45.324,584] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame
HL [06:59:24.373,840] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame
HL [06:59:24.373,901] <wrn> sw_codec_select: PCM samples dropped
HL [06:59:24.373,901] <wrn> audio_datapath: Wrong size of frame, mayge get a bad frame

maybe it useful for you

thanks
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
+1 Karl Ylvisaker over 4 years ago in reply to Zhongsan

Thank you for the update - I am glad to see that you were able to test for 8 hours continuously with so few bad frames / issues.

Please do not hesitate to open a new ticket if you should encounter any issues or questions in the future.

Good luck with your development! :)

Best regards,
Karl
Cancel
Vote Up +1 Vote Down

Sign in to reply

Reject Answer

Cancel
0 Zhongsan over 4 years ago in reply to Karl Ylvisaker

Hi, Karl

ok, next we will test the LC3 codec

thanks
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Zhongsan over 4 years ago in reply to Karl Ylvisaker

Hi, Karl

i have add a counter for bad frame, and after more than 9 hours testing, I got following information:

HL [09:08:46.645,050] <dbg> audio_datapath: audio_datapath_stream_out: Bad audio frame: 5437

the number looks a bit too much

thanks
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Karl Ylvisaker over 4 years ago in reply to Zhongsan

Hello again,

Could you describe the test setup and environment? What are between the two devices, and how is the RF noise in the environment?
5437 bad frames in the span of 9 hours equates to less than 0.0016 of frames being bad. Was there ever any audible artifacts caused by this?

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Reply

0 Karl Ylvisaker over 4 years ago in reply to Zhongsan

Hello again,

Could you describe the test setup and environment? What are between the two devices, and how is the RF noise in the environment?
5437 bad frames in the span of 9 hours equates to less than 0.0016 of frames being bad. Was there ever any audible artifacts caused by this?

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Children

0 Zhongsan over 4 years ago in reply to Karl Ylvisaker

Hi，Karl

Sounds ok, no noticeable artifacts

thanks
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Karl Ylvisaker over 4 years ago in reply to Zhongsan

Great, that is good news! :)
Then I suppose the dropped frames over that time is nothing to worry about - frames may be dropped unexpectedly from time to time due to RF noise or changes in the physical environment, but as long as it only happens as seldomly as it does in this case it should be no problem at all.
Thank you for sharing the test results with me nevertheless!

Please do not hesitate to open another ticket if you should encounter any other issues or questions in the future.

Good luck with your developing! :)

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel