Event interface error : -1 when restart playback from an HTTP(s) MP3 after STOP event (AUD-4839)

[0x0fe]

So i used the HTTP MP3 example https://github.com/espressif/esp-adf/tree/master/examples/player/pipeline_http_mp3 as a base, and i need to restart the playback after the STOP event. So i refered to another example https://github.com/espressif/esp-adf/tree/master/examples/player/pipeline_living_stream and used the same mechanism, however it could not work (content length 0) so i added pipeline_terminate, now it can work but i get 3 errors in the log. What am i doing wrong?

    while (1) {
        audio_event_iface_msg_t msg;
        esp_err_t ret = audio_event_iface_listen(evt, &msg, portMAX_DELAY);
        if (ret != ESP_OK) {
            ESP_LOGE(TAG, "[ * ] Event interface error : %d", ret);
            continue;
        }

        if (msg.source_type == AUDIO_ELEMENT_TYPE_ELEMENT
            && msg.source == (void *) mp3_decoder
            && msg.cmd == AEL_MSG_CMD_REPORT_MUSIC_INFO) {
            audio_element_info_t music_info = {0};
            audio_element_getinfo(mp3_decoder, &music_info);

            ESP_LOGI(TAG, "[ * ] Receive music info from mp3 decoder, sample_rates=%d, bits=%d, ch=%d",
                     music_info.sample_rates, music_info.bits, music_info.channels);

            i2s_stream_set_clk(i2s_stream_writer, music_info.sample_rates, music_info.bits, music_info.channels);
            continue;
        }

        //restart stream when the first pipeline element (http_stream_reader in this case) 
        //receives stop event (caused by reading errors) 
        // if (msg.source_type == AUDIO_ELEMENT_TYPE_ELEMENT && 
        //     msg.source == (void *) http_stream_reader && 
        //     msg.cmd == AEL_MSG_CMD_REPORT_STATUS && (int) 
        //     msg.data == AEL_STATUS_ERROR_OPEN) {
        if ( msg.source_type == AUDIO_ELEMENT_TYPE_ELEMENT && 
             msg.source == (void *) i2s_stream_writer && 
             msg.cmd == AEL_MSG_CMD_REPORT_STATUS && (((int)
             msg.data == AEL_STATUS_STATE_STOPPED) || ((int)
             msg.data == AEL_STATUS_STATE_FINISHED))) 
        {
            if(cnt++>6){
                break;
            }
            else{
                ESP_LOGW(TAG, "[ * ] Restart audio_pipeline");
                audio_pipeline_stop(pipeline);
                audio_pipeline_wait_for_stop(pipeline);
                audio_pipeline_terminate(pipeline);
                audio_element_reset_state(mp3_decoder);
                audio_element_reset_state(i2s_stream_writer);
                audio_pipeline_reset_ringbuffer(pipeline);
                audio_pipeline_reset_items_state(pipeline);
                audio_pipeline_run(pipeline);
                continue;
            }
        }
    }

I (947580) STREAM_DOWN: [ * ] Receive music info from mp3 decoder, sample_rates=44100, bits=16, ch=2
W (1133721) HTTP_STREAM: No more data,errno:0, total_bytes:2994349, rlen = 0
W (1135211) STREAM_DOWN: [ * ] Restart audio_pipeline
W (1135211) AUDIO_ELEMENT: [http] Element already stopped
W (1135211) AUDIO_ELEMENT: [mp3] Element already stopped
W (1135215) AUDIO_ELEMENT: [i2s] Element already stopped
E (1135226) STREAM_DOWN: [ * ] Event interface error : -1
E (1135226) STREAM_DOWN: [ * ] Event interface error : -1
E (1135230) STREAM_DOWN: [ * ] Event interface error : -1
I (1136539) STREAM_DOWN: [ * ] Receive music info from mp3 decoder, sample_rates=44100, bits=16, ch=2
W (1323796) HTTP_STREAM: No more data,errno:0, total_bytes:2994349, rlen = 0
W (1325292) STREAM_DOWN: [ * ] Restart audio_pipeline
W (1325292) AUDIO_ELEMENT: [http] Element already stopped
W (1325292) AUDIO_ELEMENT: [mp3] Element already stopped
W (1325296) AUDIO_ELEMENT: [i2s] Element already stopped
E (1325307) STREAM_DOWN: [ * ] Event interface error : -1
E (1325307) STREAM_DOWN: [ * ] Event interface error : -1
E (1325311) STREAM_DOWN: [ * ] Event interface error : -1

[jason-mao]

@0x0fe I'm not sure the exactly reason, I think it may be some queue has been taken or received before the QueueSetSelect. Would you enable the element and pipeline debug log and repeat again?

[0x0fe]

@jason-mao Ok good idea, i will figure how to do that and report.

[0x0fe]

@jason-mao So i enabled verbose debug for pipeline, element and event with :

    esp_log_level_set("*", ESP_LOG_INFO);
    esp_log_level_set("AUDIO_PIPELINE", ESP_LOG_VERBOSE);
    esp_log_level_set("AUDIO_ELEMENT", ESP_LOG_VERBOSE);
    esp_log_level_set("AUDIO_EVENT", ESP_LOG_VERBOSE);

here is the log (initial playback + 1 cycle.

I (992) esp_psram: SPI SRAM memory test OK
I (1056) cpu_start: Pro cpu start user code
I (1056) cpu_start: cpu freq: 240000000 Hz
I (1056) cpu_start: Application information:
I (1056) cpu_start: Project name:     IDF_ADF
I (1061) cpu_start: App version:      1
I (1064) cpu_start: Compile time:     Sep  8 2023 23:16:21
I (1069) cpu_start: ELF file SHA256:  a385b3bf8e0f750f...
I (1074) cpu_start: ESP-IDF:          5.0.2
I (1078) cpu_start: Min chip rev:     v3.0
I (1082) cpu_start: Max chip rev:     v3.99
I (1086) cpu_start: Chip rev:         v3.1
I (1090) heap_init: Initializing. RAM available for dynamic allocation:
I (1096) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1101) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1107) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1112) heap_init: At 3FFC5B88 len 0001A478 (105 KiB): DRAM
I (1117) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1123) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1128) heap_init: At 4009A60C len 000059F4 (22 KiB): IRAM
I (1134) esp_psram: Adding pool of 2036K of PSRAM memory to heap allocator
I (1141) spi_flash: detected chip: generic
I (1144) spi_flash: flash io: qio
W (1148) ADC: legacy driver is deprecated, please migrate to `esp_adc/adc_oneshot.h`
W (1155) i2s(legacy): legacy i2s driver is deprecated, please migrate to use driver/i2s_std.h, driver/i2s_pdm.h or driver/i2s_tdm.h
I (1167) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1179) esp_psram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1227) STREAM_DOWN: [ 1 ] Start audio codec chip
Device at 0x1a
Device at 0x1a
NAU88C22 ready, addr [0x1A]
HP vol:90
Spk vol:38
I (1276) STREAM_DOWN: [2.0] Create audio pipeline for playback
I (1276) STREAM_DOWN: [2.1] Create http stream to read data
I (1277) STREAM_DOWN: [2.2] Create i2s stream to write data to codec chip
I (1285) STREAM_DOWN: [2.3] Create mp3 decoder to decode mp3 file
I (1290) STREAM_DOWN: [2.4] Register all elements to audio pipeline
I (1296) STREAM_DOWN: [2.5] Link it together http_stream-->mp3_decoder-->i2s_stream-->[codec_chip]
I (1306) STREAM_DOWN: [2.6] Set up  uri (http as http_stream, mp3 as mp3 decoder, and default output is i2s)
I (1314) STREAM_DOWN: [ 3 ] Start and wait for Wi-Fi network
W (1901) PERIPH_WIFI: WiFi Event cb, Unhandle event_base:WIFI_EVENT, event_id:4
I (6403) STREAM_DOWN: [ 4 ] Set up  event listener
I (6404) STREAM_DOWN: [4.1] Listening event from all elements of pipeline
I (6404) STREAM_DOWN: [4.2] Listening event from peripherals
I (6409) STREAM_DOWN: [ 5 ] Start audio_pipeline
I (8433) STREAM_DOWN: [ * ] Receive music info from mp3 decoder, sample_rates=32000, bits=16, ch=2
W (69511) HTTP_STREAM: No more data,errno:0, total_bytes:843134, rlen = 0
W (71454) STREAM_DOWN: [ * ] Restart audio_pipeline
W (71454) AUDIO_ELEMENT: [http] Element already stopped
W (71455) AUDIO_ELEMENT: [mp3] Element already stopped
W (71458) AUDIO_ELEMENT: [i2s] Element already stopped
E (71471) STREAM_DOWN: [ * ] Event interface error : -1
E (71471) STREAM_DOWN: [ * ] Event interface error : -1
E (71472) STREAM_DOWN: [ * ] Event interface error : -1
I (73558) STREAM_DOWN: [ * ] Receive music info from mp3 decoder, sample_rates=32000, bits=16, ch=2
W (134845) HTTP_STREAM: No more data,errno:0, total_bytes:843134, rlen = 0