nRF5 SDK is not maintained anymore
More Info: Consider nRF Connect SDK for new designs

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

Parents

0 user87869 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 user113636 over 4 years ago in reply to user87869

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 user87869 over 3 years ago in reply to user113636

Hello again,

The behavior you describe in your ticket is something we have seen before when using the SBC codec. In essence, it is caused by sw_codec_select not handling the SBC's output properly when a bad frame occurs.
As a quick fix for this I suggest that you just remove the ERR_CHK_MSG on line 815 in this case - at worst this could sometimes produces audiable artifacts when a bad frame occurs with the SBC codec, since ctrl_blk.decoded_data contains the data from the last frame/package, which means that the same frame will be played twice.

Please try this, and let me know if it resolves the issue.

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 user113636 over 3 years ago in reply to user87869

Hi, Karl

i will testyour suggestion

thanks
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 user113636 over 3 years ago in reply to user87869

and i will replace line815 with following:

LOG_WRN("Wrong size of frame, mayge get a bad frame");
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Reply

0 user113636 over 3 years ago in reply to user87869

and i will replace line815 with following:

LOG_WRN("Wrong size of frame, mayge get a bad frame");
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Children

0 user87869 over 3 years ago in reply to user113636

Yes, that should suffice.

Let me know if you still experience this issue following the change!

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 user113636 over 3 years ago in reply to user87869

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