Pico2W crashes when sequentially streaming mp3 from URLs

[bablokb]

CircuitPython version

Adafruit CircuitPython 9.2.3 on 2025-01-17; Raspberry Pi Pico 2 W with rp2350a

Code/REPL

import time
import gc

import board
import digitalio
import audiobusio
import audiomp3

import wifi
import socketpool
import ssl
import adafruit_requests

class Player:
  def __init__(self,i2s_pins):
    self._buffer  = bytearray(16384)
    self._decoder = audiomp3.MP3Decoder("dummy.mp3", self._buffer)
    self._i2s     = audiobusio.I2SOut(*i2s_pins[:3])

    pool = socketpool.SocketPool(wifi.radio)
    self._requests = adafruit_requests.Session(pool)

  # --- play the given webradio-station   ------------------------------------

  def play(self,url):
    gc.collect()
    while True:
      try:
        self._response = self._requests.get(
          url, timeout = 5,
          headers = {"connection": "close"},
          stream = True)
        if not self._response:
          print(f"no response for {url}")
          time.sleep(1)
          continue
        self._decoder.file = self._response.socket
        self._i2s.play(self._decoder)
        return True
      except Exception as ex:
        print(f"play(): exeception: {ex}")
        return False

  # --- stop playing   -------------------------------------------------------

  def stop(self):
    """ stop playing radio stream """
    if self._i2s.playing:
      try:
        self._i2s.stop()
        self._response.socket.close()
        self._response.close()
      except Exception as ex:
        print(f"stop(): exeception: {ex}")

# --- connect-helper   --------------------------------------------------------

def connect(ssid,passwd):
  state = wifi.radio.connected
  print(f"  connected: {state}")
  if state:
    return
  for _ in range(3):
    try:
      wifi.radio.connect(ssid,passwd)
      break
    except ConnectionError as ex:
      print(f"{ex}")
  print(f"  status: {wifi.radio.connected}")
  if not wifi.radio.connected:
    raise ConnectionError(f"could not connect to {ssid}")

# --- main application code   -------------------------------------------------

connect("my_ssid","my_password")
player = Player(board.GP10  # PIN_I2S_BCLK
                board.GP11, # PIN_I2S_WSEL
                board.GP9]) # PIN_I2S_DATA

URLS = [
  "http://dispatcher.rndfnk.com/br/br1/obb/mp3/mid",
  "http://dispatcher.rndfnk.com/br/br2/live/mp3/mid",
  "http://dispatcher.rndfnk.com/br/br3/live/mp3/mid",
  "http://dispatcher.rndfnk.com/br/brklassik/live/mp3/mid",
  "http://dispatcher.rndfnk.com/br/br24/live/mp3/mid",
  "http://mdr-284350-0.cast.mdr.de/mdr/284350/0/mp3/high/stream.mp3",
  "http://icecast.ndr.de/ndr/ndrkultur/live/mp3/128/stream.mp3",
 ]

while True:
  for interval in [10,5]:
    for url in URLS:
      print(f"free memory before play(): {gc.mem_free()}")
      print(f"playing {url} for {interval}s...")
      player.play(url)
      time.sleep(interval)
      print(f"stopping player")
      player.stop()
      time.sleep(1)

Behavior

Automatisches Neuladen ist aktiviert. Speichere Dateien einfach über USB, um sie auszuführen, oder gib REPL ein, um sie zu deaktivieren.
main.py Ausgabe:
  connected: False
  status: True
free memory before play(): 313104
playing http://dispatcher.rndfnk.com/br/br1/obb/mp3/mid for 10s...
stopping player
free memory before play(): 284752
playing http://dispatcher.rndfnk.com/br/br2/live/mp3/mid for 10s...
stopping player
free memory before play(): 282480
playing http://dispatcher.rndfnk.com/br/br3/live/mp3/mid for 10s...

[15:31:46.853] Disconnected

Description

The program automatically cycles through a number of web-streams from internet radio (in the real application the user presses buttons to switch stations). After a few URLs, the Pico2W just disconnects and needs a hard reset for a restart. Behavior is random, sometime it fails after three streams, sometimes later. Switching streams seems to be the problem, playing a single stream for an extended time works without problems for all of the example URLs.

Note that you don't need real I2S hardware to reproduce the error. Also, the program works fine on an ESP32-S3.

Some speculations: maybe the network-stack of the Pico2W does not cleanup resources and fails after a while. Or it produces illegal data during close and this trips the MP3Decoder.

Additional information

No response

[eightycc]

This could be due to the gSPI clock getting divided by 3 for this board. See micropython#16057.

To eliminate this as a possibility, try changing CYW43_PIO_CLOCK_DIV_INT to 2 in ports/raspberrypi/boards/raspberry_pi_pico2_w/mpconfigboard.mk.

[bablokb]

Thanks, I will try.

[bablokb]

No change, this did not help.

[eightycc]

@bablokb Thanks for giving that a try. I was able to reproduce on a Pimoroni Pico Plus 2W with a debug build. MP3 playback is hanging up in an interrupt loop involving isr_irq10. Looks like a bug involving PIO/DMA. I've reproduced it a few times and it always winds up here:

Thread 1 "rp2350.dap.core0" received signal SIGINT, Interrupt.
0x200005aa in isr_irq10 () at audio_dma.c:465
465	    for (size_t i = 0; i < NUM_DMA_CHANNELS; i++) {
(gdb) bt
#0  0x200005aa in isr_irq10 () at audio_dma.c:465
#1  <signal handler called>
#2  audio_dma_setup_playback (dma=dma@entry=0x20024bb8, sample=sample@entry=0x2001f670, loop=loop@entry=false, single_channel_output=single_channel_output@entry=false, 
    audio_channel=<optimized out>, audio_channel@entry=0 '\000', output_signed=<optimized out>, output_signed@entry=true, output_resolution=<optimized out>, 
    output_resolution@entry=16 '\020', output_register_address=<optimized out>, dma_trigger_source=<optimized out>, swap_channel=<optimized out>, swap_channel@entry=false)
    at audio_dma.c:310
#3  0x10061dcc in common_hal_audiobusio_i2sout_play (self=self@entry=0x200249e0, sample=0x2001f670, loop=false) at common-hal/audiobusio/I2SOut.c:259
#4  0x1006ad54 in audiobusio_i2sout_obj_play (n_args=2, pos_args=0x2001c644, kw_args=0x20080b6c) at ../../shared-bindings/audiobusio/I2SOut.c:162
#5  0x100110c6 in fun_builtin_var_call (self_in=0x10119668 <audiobusio_i2sout_play_obj>, n_args=2, n_kw=0, args=0x2001c644) at ../../py/objfun.c:117
#6  0x1000bad4 in mp_call_function_n_kw (fun_in=0x10119668 <audiobusio_i2sout_play_obj>, n_args=2, n_kw=0, args=0x2001c644) at ../../py/runtime.c:736
#7  0x1000bba8 in mp_call_method_n_kw (n_args=<optimized out>, n_kw=<optimized out>, args=args@entry=0x2001c640) at ../../py/runtime.c:752
#8  0x20006a14 in mp_execute_bytecode (code_state=code_state@entry=0x2001c62c, inject_exc=inject_exc@entry=0x0) at ../../py/vm.c:1064
#9  0x2000685c in fun_bc_call (self_in=0x2001cf00, n_args=2, n_kw=0, args=0x2001c61c) at ../../py/objfun.c:271
#10 0x1000bad4 in mp_call_function_n_kw (fun_in=0x2001cf00, n_args=2, n_kw=0, args=0x2001c61c) at ../../py/runtime.c:736
#11 0x1000bba8 in mp_call_method_n_kw (n_args=<optimized out>, n_kw=<optimized out>, args=args@entry=0x2001c618) at ../../py/runtime.c:752
#12 0x20006a14 in mp_execute_bytecode (code_state=code_state@entry=0x2001c5e4, inject_exc=inject_exc@entry=0x0) at ../../py/vm.c:1064
#13 0x2000685c in fun_bc_call (self_in=0x2001ccc0, n_args=0, n_kw=0, args=0x0) at ../../py/objfun.c:271
#14 0x1000bad4 in mp_call_function_n_kw (fun_in=fun_in@entry=0x2001ccc0, n_args=n_args@entry=0, n_kw=n_kw@entry=0, args=args@entry=0x0) at ../../py/runtime.c:736
#15 0x1000baf8 in mp_call_function_0 (fun=fun@entry=0x2001ccc0) at ../../py/runtime.c:710
#16 0x1000bb3e in mp_parse_compile_execute (lex=0x2001cf40, parse_input_kind=parse_input_kind@entry=MP_PARSE_FILE_INPUT, globals=globals@entry=0x20008468 <mp_state_ctx+160>, 
    locals=locals@entry=0x20008468 <mp_state_ctx+160>) at ../../py/runtime.c:1746
#17 0x1001a014 in eval_exec_helper (n_args=<optimized out>, args=<optimized out>, parse_input_kind=parse_input_kind@entry=MP_PARSE_FILE_INPUT) at ../../py/builtinevex.c:158
#18 0x1001a06a in mp_builtin_exec (n_args=<optimized out>, args=<optimized out>) at ../../py/builtinevex.c:167
#19 0x100110a0 in fun_builtin_var_call (self_in=0x100d31d8 <mp_builtin_exec_obj>, n_args=1, n_kw=0, args=0x2001c5d8) at ../../py/objfun.c:122
#20 0x1000bad4 in mp_call_function_n_kw (fun_in=0x100d31d8 <mp_builtin_exec_obj>, n_args=1, n_kw=0, args=args@entry=0x2001c5d8) at ../../py/runtime.c:736
#21 0x20006ed6 in mp_execute_bytecode (code_state=code_state@entry=0x2001c5bc, inject_exc=inject_exc@entry=0x0) at ../../py/vm.c:979
#22 0x2000685c in fun_bc_call (self_in=0x2001ce00, n_args=0, n_kw=0, args=0x0) at ../../py/objfun.c:271
#23 0x1000bad4 in mp_call_function_n_kw (fun_in=fun_in@entry=0x2001ce00, n_args=n_args@entry=0, n_kw=n_kw@entry=0, args=args@entry=0x0) at ../../py/runtime.c:736
#24 0x1000baf8 in mp_call_function_0 (fun=fun@entry=0x2001ce00) at ../../py/runtime.c:710
#25 0x10094234 in parse_compile_execute (source=source@entry=0x20080f88, input_kind=<optimized out>, exec_flags=exec_flags@entry=22, result=result@entry=0x0)
    at ../../shared/runtime/pyexec.c:161
#26 0x100944ca in pyexec_friendly_repl () at ../../shared/runtime/pyexec.c:769
#27 0x1001eb98 in run_repl (safe_mode=SAFE_MODE_NONE) at ../../main.c:950
#28 0x1001f13e in main () at ../../main.c:1108

[dhalbert]

I made a change in #9980 which was fixing a different crash involving picodvi. I don't think it would fix this, but you might try an artifact build from from that PR.

[eightycc]

Same failure with the artifact from #9980.

Adafruit CircuitPython 9.2.3-1-g5a9e682173 on 2025-01-19; Pimoroni Pico Plus 2 W with rp2350b

[bablokb]

@eightycc Thanks for the analysis. Just to learn something for the future: how do I get the backtrace? Is it automatic with creating a build with make ... DEBUG=1 and running it? But that would not start gdb I assume.

[eightycc]

The backtrace is from the GDB command bt. I build with DEBUG=1 to get symbols and object code that's partially optimized but not to the extent that it's too scrambled to make sense of. My test hardware is an RP2040 board running debugprobe attached to SWD and a serial port on the Pimoroni Pico Plus2W. The other tool is OpenOCD, I use the Raspberry Pi Foundation's fork. I follow the instructions in Appendix A of "Getting Started with Raspberry Raspberry Pi Pico Series".

[eightycc]

The interrupt loop and the state of the DMA section are interesting. CircuitPython overrides isr_dma_0() with its own implementation. The loop occurs because DMA is raising the IRQ due to bits set in DMA_INTS0, specifically those for channels 7 and 10. Since CP's isr_dma_0() doesn't test any of the DMA_INTSx bits in IRQs, it loops. It's strange and unexpected that DMA_INTS0 bits are set for these channels.

[dhalbert]

CircuitPython overrides isr_dma_0() with its own implementation.

This is not a good idea and I want to fix this. There is discussion in #9868 about this, and #9980 uses that routine. As a first step for solving #9868, I want to make DMA0 be the shared DMA used for multiple purposes. I am awaiting some reworked tests to test #9980. After that, I'll switch to using irq_add_shared_handler() for all the uses of DMA0, and re-test.

Right now that routine has to be changed for each piece of functionality that uses DMA0 irq's.

I haven't looked at this issue in any detail. Is there a simple addition to the fixed routine now that you can add?

[eightycc]

Is there a simple addition to the fixed routine now that you can add?

Since the pending interrupts didn't appear in data_hw->intr, I changed the code to scan data_hw->ints0. No dice. The code sees the ints0 bit, writes it to clear it, but it remains set in the hardware. Maybe a deeper channel/irq config issue I'm not seeing?

[eightycc]

From the "I can't fix it, but I can bypass it with one of these" department: The data_hw->ints0 bits for channels 7 and 10 were coming on because something is setting the corresponding channel bits in data_hw->intf0. A combination of testing data_hw->ints0 instead of data_hw->intr and clearing any bits set in data_hw->intf0 fixes (actually it bypasses) the bug. I still cannot explain how those bits got set in the first place.

void __not_in_flash_func(isr_dma_0)(void) {
    for (size_t i = 0; i < NUM_DMA_CHANNELS; i++) {
        uint32_t mask = 1 << i;
        if ((dma_hw->ints0 & mask) == 0) {
            continue;
        }
        // Clear any forced interrupts for this channel.
        if ((dma_hw->intf0 & mask) != 0) {
            dma_hw->intf0 &= ~mask;
        }
        // acknowledge interrupt early. Doing so late means that you could lose an
        // interrupt if the buffer is very small and the DMA operation
        // completed by the time callback_add() / dma_complete() returned. This
        // affected PIO continuous write more than audio.
        dma_hw->ints0 = mask;
        if (MP_STATE_PORT(playing_audio)[i] != NULL) {
            audio_dma_t *dma = MP_STATE_PORT(playing_audio)[i];
            // Record all channels whose DMA has completed; they need loading.
            dma->channels_to_load_mask |= mask;
            background_callback_add(&dma->callback, dma_callback_fun, (void *)dma);
        }
        if (MP_STATE_PORT(background_pio)[i] != NULL) {
            rp2pio_statemachine_obj_t *pio = MP_STATE_PORT(background_pio)[i];
            rp2pio_statemachine_dma_complete_write(pio, i);
        }
    }
}

[eightycc]

audio_dma_load_next_block() is clobbering dma_hw->intf0 via dma_channel_set_trans_count(), but it's not its fault. It gets called by audio_dma_setup_playback() with a buffer_idx parm that selects a null DMA channel (== 16) in dma->channel[]. Why that happens is TBD.

[jepler]

Maybe related? I added code in #9680 to acknowledge a previous pending interrupt in state machine background write befor setting the interrupt enabled flag.. I never determined why the IRQ flag was pending, and it wasn't clear whether I was hiding a deeper problem.

[bablokb]

Yes, this fixed it, thanks! I built a new version and tested with the real application as well.

[eightycc]

@bablokb Good to know. The root cause is missing code to handle the case where the MP3 decoder fails to synchronize with the first buffer of the stream. This leads to a cascade of errors that eventually hangs in an interrupt loop. To actually fix the bug I'm detecting the error and throwing an "Audio source error" from the player when it occurs. Your code will need to catch and retry for this case. I'll be submitting a PR shortly.