random speed of playback

[BigBobbas]

Hi, I am currently testing in ESPHome 2024.2.0 . with an ESP32-s3-N16R8. When I stream some mp3 files, tts using piper or nabu casa and radio using 'radio browser' the playback speed varies from very fast to very slow with no obvious pattern, but never at the correct speed. If I play music mp3s from a dlna server the audio has been at the correct speed. any more details I can provide. I am more than happy to help, as this has been needed in ESPHome for a long time!

Thanks for your help :)

[gnumpi]

Hey thanks for your testing. Today I uploaded a fix which probably addressed exactly that issue. Before that update, the number of channels and sampling rate where not always changed correctly when switching between audio sources. Could you try to test the latest version and report if the issue still occurs?

[BigBobbas]

thank you for fast response, I managed to play 1 tts and that was the correct speed, however any more and it's causing the esp to re-boot. Also micro_wake_word is no longer working. I will get serial logs to see if I can get some further info. but these were the current OTA logs [15:02:26][D][api:102]: Accepted 192.168.1.8 [15:02:26][D][api.connection:1121]: Home Assistant 2024.2.2 (192.168.1.8): Connected successfully [15:02:26][W][micro_wake_word:150]: Wake word is already running [15:02:57][D][media_player:059]: 's3-dev_media_player' - Setting [15:02:57][D][media_player:066]: Media URL: http://192.168.1.8:8123/api/tts_proxy/5d08b70703f04dd0a242f6d920a73aa6dfb94212_en-in_117c0bb326_cloud.mp3 [15:02:57][I][esp_adf_pipeline:011]: Init request, current state 5 [15:02:57][D][esp-idf:000]: I (53499) AUDIO_THREAD: The http task allocate stack on external memory

[15:02:57][D][esp-idf:000]: I (53502) AUDIO_ELEMENT: [http-0x3d820144] Element task created

[15:02:57][D][esp-idf:000]: I (53504) AUDIO_THREAD: The decoder task allocate stack on external memory

[15:02:57][D][esp-idf:000]: I (53506) AUDIO_ELEMENT: [decoder-0x3d8202fc] Element task created

[15:02:57][D][esp-idf:000]: I (53508) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1

[15:02:57][D][esp-idf:000]: I (53510) AUDIO_ELEMENT: [decoder] AEL_MSG_CMD_RESUME,state:1

[15:02:57][D][esp-idf:000]: I (53514) MP3_DECODER: MP3 opened

[15:02:57][D][esp-idf:000]: I (53568) HTTP_CLIENT: Body received in fetch header state, 0x3fcbefef, 1841

[15:02:57][D][esp-idf:000]: I (53571) HTTP_STREAM: total_bytes=21734

[15:02:57][I][esp_adf_pipeline:245]: [ ] CMD: 10 Pipeline: 1 [15:02:57][I][esp_adf_pipeline:245]: [ ] CMD: 8 Pipeline: 1 [15:02:57][I][esp_adf_pipeline:250]: [ http ] status: 12 [15:02:57][I][esp_adf_pipeline:245]: [ ] CMD: 8 Pipeline: 1 [15:02:57][I][esp_adf_pipeline:250]: [ decoder ] status: 12 [15:02:57][I][HTTPStreamReader:090]: [ ] Receive music info from mp3 decoder, sample_rates=24000, bits=16, ch=1 WARNING esp-idf @ 192.168.1.203: Connection error occurred: [Errno 104] Connection reset by peer INFO Processing unexpected disconnect from ESPHome API for esp-idf @ 192.168.1.203 WARNING Disconnected from API INFO Successfully connected to esp-idf @ 192.168.1.203 in 0.003s INFO Successful handshake with esp-idf @ 192.168.1.203 in 0.033s [15:03:26][D][api:102]: Accepted 192.168.1.8 [15:03:26][D][api.connection:1121]: Home Assistant 2024.2.2 (192.168.1.8): Connected successfully [15:03:26][W][micro_wake_word:150]: Wake word is already running [15:06:43][D][media_player:059]: 's3-dev_media_player' - Setting [15:06:43][D][media_player:066]: Media URL: http://192.168.1.8:8123/api/tts_proxy/5d08b70703f04dd0a242f6d920a73aa6dfb94212_en-in_117c0bb326_cloud.mp3 [15:06:43][I][esp_adf_pipeline:011]: Init request, current state 5 [15:06:43][D][esp-idf:000]: I (221839) AUDIO_THREAD: The http task allocate stack on external memory

[15:06:43][D][esp-idf:000]: I (221842) AUDIO_ELEMENT: [http-0x3d820144] Element task created

[15:06:43][D][esp-idf:000]: I (221844) AUDIO_THREAD: The decoder task allocate stack on external memory

[15:06:43][D][esp-idf:000]: I (221847) AUDIO_ELEMENT: [decoder-0x3d8202fc] Element task created

[15:06:43][D][esp-idf:000]: I (221849) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1

[15:06:43][D][esp-idf:000]: I (221853) AUDIO_ELEMENT: [decoder] AEL_MSG_CMD_RESUME,state:1

[15:06:43][D][esp-idf:000]: [15:06:43][D][esp-idf:000]: [15:06:43][I][esp_audio_sources:059]: decoder status: 2 [15:06:43][I][esp_adf_pipeline:025]: Starting request, current state 5 [15:06:43][I][adf_audio:134]: got new pipeline state: 1 [15:06:43][I][esp_adf_pipeline:098]: set_new_state: 1 [15:06:43][D][esp-idf:000]: I (221884) HTTP_STREAM: total_bytes=21734

[15:06:43][I][esp_adf_pipeline:245]: [ ] CMD: 10 Pipeline: 1 [15:06:43][I][esp_adf_pipeline:245]: [ ] CMD: 8 Pipeline: 1 [15:06:43][I][esp_adf_pipeline:250]: [ http ] status: 12 [15:06:43][I][esp_adf_pipeline:245]: [ ] CMD: 8 Pipeline: 1 [15:06:44][I][esp_adf_pipeline:250]: [ decoder ] status: 12 [15:06:44][I][HTTPStreamReader:090]: [ ] Receive music info from mp3 decoder, sample_rates=24000, bits=16, ch=1

[gnumpi]

Ohhh no!!! Ok, thanks for reporting, I probably can look into it tomorrow.

[BigBobbas]

no problem, there is no hurry.

[gnumpi]

Could you share your config and which DAC you are using?

[BigBobbas]

DAC is a MAX98357 and config below

esphome:
  name: esp-idf
  platformio_options:
    board_build.flash_mode: dio
esp32:
  board: esp32-s3-devkitc-1
  variant: esp32s3
  framework:
    type: esp-idf
    version: recommended
    sdkconfig_options:
      CONFIG_ESP32_S3_BOX_BOARD: "y"

psram:
  mode: octal
  speed: 80MHz

logger:

ota:

wifi:
    ssid: !secret wifi_ssid
    password: !secret wifi_password
api:
  on_client_connected: 
    - micro_wake_word.start

external_components:
  - source:
      type: local
      path: custom
    components: [ adf_pipeline, i2s_audio ]

button:
  - platform: restart
    id: reboot
    name: "Reboot"
i2s_audio:
  - id: i2s_in
    i2s_lrclk_pin: GPIO5
    i2s_bclk_pin: GPIO6
  - id: i2s_out
    i2s_lrclk_pin: GPIO46
    i2s_bclk_pin: GPIO9

adf_pipeline:
  - platform: i2s_audio
    type: sink
    id: adf_i2s_out
    i2s_audio_id: i2s_out
    i2s_dout_pin: GPIO10

  - platform: i2s_audio
    type: source
    id: adf_i2s_in
    i2s_audio_id: i2s_in
    i2s_din_pin: GPIO4
    channel: left
    sample_rate: 16000
    bits_per_sample: 16bit

microphone:
  - platform: adf_pipeline
    id: adf_microphone
    pipeline:
      - adf_i2s_in
      - self

#speaker:
#  - platform: adf_pipeline
#    id: adf_speaker
#    pipeline:
#      - self
#      - adf_i2s_out

media_player:
  - platform: adf_pipeline
    id: adf_media_player
    name: s3-dev_media_player
    internal: false
    pipeline:
      - self
      - adf_i2s_out

micro_wake_word:
  model: hey_jarvis
  on_wake_word_detected:  
      - media_player.play_media: http://192.168.1.8:8123/local/vad.mp3
      - voice_assistant.start:

voice_assistant:
  id: va
  microphone: adf_microphone
  media_player: adf_media_player
  noise_suppression_level: 2
  auto_gain: 16dBFS
  volume_multiplier: 6
  use_wake_word: false
  on_end:
      then:
        - wait_until:
            not:
              voice_assistant.is_running:
        - voice_assistant.stop
        - micro_wake_word.start:

[BigBobbas]

these are serial logs where it crashes

[I][esp_adf_pipeline:098]: set_new_state: 1
[D][esp-idf:000]: I (38560) HTTP_CLIENT: Body received in fetch header state, 0x3fcbef97, 1841

[D][esp-idf:000]: I (38566) HTTP_STREAM: total_bytes=21734

[I][esp_adf_pipeline:245]: [ * ] CMD: 10 Pipeline: 1
[I][esp_adf_pipeline:245]: [ * ] CMD: 8 Pipeline: 1
[I][esp_adf_pipeline:250]: [ http ] status: 12
[I][esp_adf_pipeline:245]: [ * ] CMD: 8 Pipeline: 1
[I][esp_adf_pipeline:250]: [ decoder ] status: 12
[I][HTTPStreamReader:090]: [ * ] Receive music info from mp3 decoder, sample_rates=24000, bits=16, ch=1
E (43587) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (43587) task_wdt:  - loopTask (CPU 1)
E (43587) task_wdt: Tasks currently running:
E (43587) task_wdt: CPU 0: IDLE
E (43587) task_wdt: CPU 1: IDLE
E (43587) task_wdt: Aborting.

abort() was called at PC 0x4204b918 on core 0

Backtrace: 0x403768f2:0x3fc98160 0x4037d8d9:0x3fc98180 0x403843fe:0x3fc981a0 0x4204b918:0x3fc98210 0x40377265:0x3fc98230 0x420c54f7:0x3fcf4310 0x4204c0f9:0x3fcf4330 0x4037ede0:0x3fcf4350

ELF file SHA256: b835ced0f629a70c

Rebooting...
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40376500
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3808,len:0x1658
load:0x403c9700,len:0xbc0
load:0x403cc700,len:0x2f3c
entry 0x403c9950

[gnumpi]

Thanks for sharing the logs! It turned out that I messed up the detection for a pipeline status change. I committed some fixes into the 8-random-speed-of-playback branch, could you try if the update is of any help for your problem?

[BigBobbas]

i will give that a test this morning and update you , thanks for your quick response,

[BigBobbas]

ok that appears to be working great now with micro_wake_word and the correct speed for tts. I will use it actively over the next day or so and see how it goes. but i really think esphome devs need to be looking at this, if they're not already! this is excellent work.

[gnumpi]

Thanks a lot, and yes, please keep me updated if you run into any problems during your active usage tests ....

[BigBobbas]

all is going really well thank you. the only one thing I have noticed is that the media player won't respond to media_player.stop only pause

[gnumpi]

ahhhh, ok! So far I only tested it using the home assistant ui, and there is now stop button ;) Thanks for pointing at it, I will add the stop functionality.