[X] This issue only contains 1 issue (if you have multiple issues, open one issue for each issue).
[X] This issue is not a duplicate issue of currently previous issues..
[X] I am able to consult debug logging for my ESPHome instance.
Describe the issue
I just updated one of my satellites with the latest fix for the too loud or too silent bug. Since then even when I "disable" the fix, I got issues that the audio response take very long.
This is what I see in the log:
[10:46:35][D][adf_audio_element:324]: [i2s_in] Checking State for stopping, got 3
[10:46:35][D][adf_audio_element:324]: [pcm_reader] Checking State for stopping, got 3
[10:46:35][D][esp-idf:000][i2s_in]: W (931707) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[10:46:35][D][esp-idf:000][i2s_in]: W (931710) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[10:46:35][D][esp-idf:000][i2s_in]: W (931714) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[10:46:35][D][esp-idf:000][i2s_in]: W (931717) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[10:46:35][D][esp-idf:000][i2s_in]: W (931722) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[10:46:35][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from ABORTING to STOPPED. (REQ: 1)
[10:46:35][D][voice_assistant:504]: State changed from STOPPING_MICROPHONE to AWAITING_RESPONSE
[10:46:35][D][voice_assistant:627]: Event Type: 4
[10:46:35][D][voice_assistant:655]: Speech recognised as: "What's the temperature?"
[10:46:35][D][voice_assistant:627]: Event Type: 5
[10:46:35][D][voice_assistant:660]: Intent started
Issue is that, the audio response after the first response (reboot) or after a ceratin amount of time (1-2 minutes), is hanging. If I leave the satellite alone the response is coming like 15-30 seconds afterwards. But I can force the response when I just press one of the volume buttons.
I can only think that there is something with the libraries and not the code itself here, because there was nothing changed since my last update. ESPHome version is 2024.6.6
Reproduction steps
Reboot / Power on
Speak wakeword and command, audio response immediately
Wait 3-4 seconds
Speak wakeword and command, no audio response within the next 15-30 seconds (bluelights blinking)
Pressing volume up or volume down after wakeword + command immediate audio response
Wait 2 minutes after last wakeword and command, audio response instantly
...
Debug logs
[11:15:32][I][app:100]: ESPHome version 2024.6.6 compiled on Jul 15 2024, 10:51:41
[11:15:32][C][wifi:599]: WiFi:
[11:15:32][C][wifi:427]: Local MAC: EC:DA:3B:54:80:60
[11:15:32][C][wifi:432]: SSID: XXX
[11:15:32][C][wifi:435]: IP Address: XXX
[11:15:32][C][wifi:439]: BSSID: XXX
[11:15:32][C][wifi:440]: Hostname: 'voice-xxx'
[11:15:32][C][wifi:442]: Signal strength: -50 dB ▂▄▆█
[11:15:32][C][wifi:446]: Channel: 6
[11:15:32][C][wifi:447]: Subnet: XXX
[11:15:32][C][wifi:448]: Gateway: XXX
[11:15:32][C][wifi:449]: DNS1: 0.0.0.0
[11:15:32][C][wifi:450]: DNS2: 0.0.0.0
[11:15:32][C][logger:185]: Logger:
[11:15:32][C][logger:186]: Level: DEBUG
[11:15:32][C][logger:188]: Log Baud Rate: 115200
[11:15:32][C][logger:189]: Hardware UART: USB_SERIAL_JTAG
[11:15:32][C][template.number:050]: Template Number 'Touch threshold percentage'
[11:15:32][C][template.number:051]: Optimistic: YES
[11:15:32][C][template.number:052]: Update Interval: never
[11:15:32][C][esp32_rmt_led_strip:175]: ESP32 RMT LED Strip:
[11:15:32][C][esp32_rmt_led_strip:176]: Pin: 11
[11:15:32][C][esp32_rmt_led_strip:177]: Channel: 0
[11:15:32][C][esp32_rmt_led_strip:202]: RGB Order: GRB
[11:15:32][C][esp32_rmt_led_strip:203]: Max refresh rate: 0
[11:15:32][C][esp32_rmt_led_strip:204]: Number of LEDs: 6
[11:15:32][C][switch.gpio:068]: GPIO Switch 'dac_mute'
[11:15:32][C][switch.gpio:091]: Restore Mode: always OFF
[11:15:32][C][switch.gpio:031]: Pin: GPIO21
[11:15:32][D][binary_sensor:036]: 'volume_up': Sending state OFF
[11:15:32][D][light:036]: 'right_led' Setting:
[11:15:32][D][light:047]: State: OFF
[11:15:32][D][light:085]: Transition length: 0.1s
[11:15:32][C][gpio.binary_sensor:015]: GPIO Binary Sensor 'Disable wake word'
[11:15:32][C][gpio.binary_sensor:016]: Pin: GPIO38
[11:15:32][C][light:103]: Light 'leds'
[11:15:32][C][light:105]: Default Transition Length: 0.0s
[11:15:32][C][light:106]: Gamma Correct: 2.80
[11:15:32][C][light:103]: Light 'left_led'
[11:15:32][C][light:105]: Default Transition Length: 0.1s
[11:15:32][C][light:106]: Gamma Correct: 2.80
[11:15:32][C][light:103]: Light 'top_led'
[11:15:32][C][light:105]: Default Transition Length: 0.1s
[11:15:32][C][light:106]: Gamma Correct: 2.80
[11:15:32][C][light:103]: Light 'right_led'
[11:15:32][C][light:105]: Default Transition Length: 0.1s
[11:15:32][C][light:106]: Gamma Correct: 2.80
[11:15:32][C][template.switch:068]: Template Switch 'Use Wake Word'
[11:15:32][C][template.switch:091]: Restore Mode: restore defaults to ON
[11:15:32][C][template.switch:057]: Optimistic: YES
[11:15:32][C][psram:020]: PSRAM:
[11:15:32][C][psram:021]: Available: YES
[11:15:32][C][psram:024]: Size: 8191 KB
[11:15:32][C][i2s_audio:028]: I2SController:
[11:15:32][C][i2s_audio:029]: AccessMode: duplex
[11:15:32][C][i2s_audio:030]: Port: 0
[11:15:32][C][i2s_audio:032]: Reader registered.
[11:15:32][C][i2s_audio:035]: Writer registered.
[11:15:32][C][i2s_audio:139]: I2S-Writer (Fixed-CFG):
[11:15:32][C][i2s_audio:141]: sample-rate: 16000 bits_per_sample: 32
[11:15:32][C][i2s_audio:142]: channel_fmt: 4 channels: 1
[11:15:32][C][i2s_audio:143]: use_apll: no, use_pdm: no
[11:15:32][C][i2s_audio:136]: I2S-Reader (Fixed-CFG):
[11:15:33][C][i2s_audio:141]: sample-rate: 16000 bits_per_sample: 32
[11:15:33][C][i2s_audio:142]: channel_fmt: 4 channels: 1
[11:15:33][C][i2s_audio:143]: use_apll: no, use_pdm: no
[11:15:33][C][esp32_touch:073]: Config for ESP32 Touch Hub:
[11:15:33][C][esp32_touch:074]: Meas cycle: 0.80ms
[11:15:33][C][esp32_touch:075]: Sleep cycle: 2.00ms
[11:15:33][C][esp32_touch:095]: Low Voltage Reference: 0.8V
[11:15:33][C][esp32_touch:115]: High Voltage Reference: 2.4V
[11:15:33][C][esp32_touch:135]: Voltage Attenuation: 0V
[11:15:33][C][esp32_touch:169]: Filter mode: IIR_16
[11:15:33][C][esp32_touch:170]: Debounce count: 2
[11:15:33][C][esp32_touch:171]: Noise threshold coefficient: 0
[11:15:33][C][esp32_touch:172]: Jitter filter step size: 0
[11:15:33][C][esp32_touch:191]: Smooth level: IIR_2
[11:15:33][C][esp32_touch:213]: Denoise grade: BIT8
[11:15:33][C][esp32_touch:245]: Denoise capacitance level: L0
[11:15:33][C][esp32_touch:260]: Touch Pad 'volume_down'
[11:15:33][C][esp32_touch:261]: Pad: T4
[11:15:33][C][esp32_touch:262]: Threshold: 459674
[11:15:33][C][esp32_touch:260]: Touch Pad 'volume_up'
[11:15:33][C][esp32_touch:261]: Pad: T2
[11:15:33][C][esp32_touch:262]: Threshold: 493962
[11:15:33][C][esp32_touch:260]: Touch Pad 'action'
[11:15:33][C][esp32_touch:261]: Pad: T3
[11:15:33][C][esp32_touch:262]: Threshold: 615950
[11:15:33][C][captive_portal:088]: Captive Portal:
[11:15:33][C][mdns:115]: mDNS:
[11:15:33][C][mdns:116]: Hostname: voice-xxx
[11:15:33][C][esphome.ota:073]: Over-The-Air updates:
[11:15:33][C][esphome.ota:074]: Address: xxx
[11:15:33][C][esphome.ota:075]: Version: 2
[11:15:33][C][esphome.ota:078]: Password configured
[11:15:33][D][light:036]: 'top_led' Setting:
[11:15:33][D][light:051]: Brightness: 60%
[11:15:33][D][light:059]: Red: 100%, Green: 0%, Blue: 100%
[11:15:33][D][light:109]: Effect: 'listening_ww'
[11:15:33][C][safe_mode:018]: Safe Mode:
[11:15:33][C][safe_mode:020]: Boot considered successful after 60 seconds
[11:15:33][C][safe_mode:021]: Invoke after 10 boot attempts
[11:15:33][C][safe_mode:023]: Remain in safe mode for 300 seconds
[11:15:33][C][api:139]: API Server:
[11:15:33][C][api:140]: Address: xxx
[11:15:33][C][api:142]: Using noise encryption: YES
[11:15:33][C][improv_serial:032]: Improv Serial:
[11:15:33][C][micro_wake_word:058]: microWakeWord:
[11:15:33][C][micro_wake_word:059]: Wake Word: hey jarvis
[11:15:33][C][micro_wake_word:060]: Probability cutoff: 0.500
[11:15:33][C][micro_wake_word:061]: Sliding window size: 10
[11:15:33][C][esp_adf_pipeline.microphone:020]: ADF-Microphone
[11:15:33][C][adf_media_player:016]: ESP-ADF-MediaPlayer:
[11:15:33][C][adf_media_player:018]: MP_ANNOUNCE enabled
[11:15:33][C][adf_media_player:024]: Number of ADFComponents: 3
[11:15:38][D][micro_wake_word:363]: Wake word sliding average probability is 0.531 and most recent probability is 0.906
[11:15:38][D][micro_wake_word:129]: Wake Word Detected
[11:15:38][D][micro_wake_word:178]: State changed from DETECTING_WAKE_WORD to STOP_MICROPHONE
[11:15:38][D][micro_wake_word:135]: Stopping Microphone
[11:15:38][D][esp_adf_pipeline:070]: Called 'stop' while in RUNNING state.
[11:15:38][D][micro_wake_word:178]: State changed from STOP_MICROPHONE to STOPPING_MICROPHONE
[11:15:38][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from RUNNING to ABORTING. (REQ: 1)
[11:15:38][D][adf_audio_element:324]: [i2s_in] Checking State for stopping, got 3
[11:15:38][D][esp-idf:000][i2s_in]: W (1056261) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:38][D][esp-idf:000][i2s_in]: W (1056264) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:38][D][esp-idf:000][i2s_in]: W (1056267) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:38][D][esp-idf:000][i2s_in]: W (1056271) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:38][D][esp-idf:000][i2s_in]: W (1056274) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:38][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from ABORTING to STOPPED. (REQ: 1)
[11:15:38][D][micro_wake_word:178]: State changed from STOPPING_MICROPHONE to IDLE
[11:15:38][D][voice_assistant:504]: State changed from IDLE to START_MICROPHONE
[11:15:38][D][voice_assistant:510]: Desired state set to START_PIPELINE
[11:15:38][D][voice_assistant:221]: Starting Microphone
[11:15:38][D][esp_adf_pipeline.microphone:025]: start request while ine state 0
[11:15:38][D][esp_adf_pipeline:060]: Starting request, current state STOPPED
[11:15:38][D][voice_assistant:504]: State changed from START_MICROPHONE to STARTING_MICROPHONE
[11:15:38][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from STOPPED to PREPARING. (REQ: 0)
[11:15:38][D][adf_audio_element:108]: Preparing [i2s_in]...
[11:15:38][D][adf_audio_element:108]: Preparing [pcm_reader]...
[11:15:38][D][esp_adf_pipeline:342]: wait for preparation, done
[11:15:38][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from PREPARING to STARTING. (REQ: 0)
[11:15:38][D][adf_audio_element:165]: Resuming [i2s_in]...
[11:15:38][D][adf_audio_element:172]: [i2s_in] Sending resume command.
[11:15:38][D][esp-idf:000][i2s_in]: I (1056351) AUDIO_ELEMENT: [i2s_in] AEL_MSG_CMD_RESUME,state:1
[11:15:38][D][adf_audio_element:191]: [pcm_reader] Checking State, got 65
[11:15:38][I][esp_adf_pipeline:132]: [ i2s_in ] status: 12
[11:15:38][D][adf_audio_element:191]: [i2s_in] Checking State, got 78
[11:15:38][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from STARTING to RUNNING. (REQ: 0)
[11:15:38][D][voice_assistant:504]: State changed from STARTING_MICROPHONE to START_PIPELINE
[11:15:38][D][voice_assistant:275]: Requesting start...
[11:15:38][D][voice_assistant:504]: State changed from START_PIPELINE to STARTING_PIPELINE
[11:15:38][D][voice_assistant:525]: Client started, streaming microphone
[11:15:38][D][voice_assistant:504]: State changed from STARTING_PIPELINE to STREAMING_MICROPHONE
[11:15:38][D][voice_assistant:510]: Desired state set to STREAMING_MICROPHONE
[11:15:38][D][voice_assistant:627]: Event Type: 1
[11:15:38][D][voice_assistant:630]: Assist Pipeline running
[11:15:38][D][voice_assistant:627]: Event Type: 3
[11:15:38][D][voice_assistant:641]: STT started
[11:15:38][D][light:036]: 'top_led' Setting:
[11:15:38][D][light:051]: Brightness: 100%
[11:15:38][D][light:059]: Red: 100%, Green: 100%, Blue: 100%
[11:15:38][D][light:109]: Effect: 'listening'
[11:15:39][D][voice_assistant:627]: Event Type: 11
[11:15:39][D][voice_assistant:781]: Starting STT by VAD
[11:15:40][D][voice_assistant:627]: Event Type: 12
[11:15:40][D][voice_assistant:785]: STT by VAD end
[11:15:40][D][voice_assistant:504]: State changed from STREAMING_MICROPHONE to STOP_MICROPHONE
[11:15:40][D][voice_assistant:510]: Desired state set to AWAITING_RESPONSE
[11:15:40][D][esp_adf_pipeline:070]: Called 'stop' while in RUNNING state.
[11:15:40][D][voice_assistant:504]: State changed from STOP_MICROPHONE to STOPPING_MICROPHONE
[11:15:40][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from RUNNING to ABORTING. (REQ: 1)
[11:15:40][D][light:036]: 'top_led' Setting:
[11:15:40][D][light:051]: Brightness: 70%
[11:15:40][D][light:059]: Red: 0%, Green: 20%, Blue: 100%
[11:15:40][D][light:109]: Effect: 'processing'
[11:15:40][D][adf_audio_element:324]: [i2s_in] Checking State for stopping, got 3
[11:15:40][D][adf_audio_element:324]: [pcm_reader] Checking State for stopping, got 3
[11:15:40][D][esp-idf:000][i2s_in]: W (1058340) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:40][D][esp-idf:000][i2s_in]: W (1058345) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:40][D][esp-idf:000][i2s_in]: W (1058349) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:40][D][esp-idf:000][i2s_in]: W (1058353) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:40][D][esp-idf:000][i2s_in]: W (1058358) AUDIO_ELEMENT: OUT-[i2s_in] AEL_IO_ABORT
[11:15:40][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from ABORTING to STOPPED. (REQ: 1)
[11:15:40][D][voice_assistant:504]: State changed from STOPPING_MICROPHONE to AWAITING_RESPONSE
[11:15:40][D][voice_assistant:627]: Event Type: 4
[11:15:40][D][voice_assistant:655]: Speech recognised as: "What's the temperature?"
[11:15:40][D][voice_assistant:627]: Event Type: 5
[11:15:40][D][voice_assistant:660]: Intent started
[11:15:44][D][binary_sensor:036]: 'volume_up': Sending state ON
[11:15:44][D][light:036]: 'right_led' Setting:
[11:15:44][D][light:047]: State: ON
[11:15:44][D][light:085]: Transition length: 0.1s
[11:15:44][D][media_player:061]: 'voice-buero' - Setting
[11:15:44][D][media_player:071]: Volume: 0.50
[11:15:44][D][adf_i2s_out:141]: Set final i2s settings: 16000
[11:15:44][D][esp_audio_processors:124]: Current settings: SRC: rate: 24000, ch: 1 bits: 16, DST: rate: 16000, ch: 1, bits 16
[11:15:44][D][light:036]: 'top_led' Setting:
[11:15:44][D][light:109]: Effect: 'show_volume'
[11:15:44][D][voice_assistant:627]: Event Type: 6
[11:15:44][D][voice_assistant:627]: Event Type: 7
[11:15:44][D][voice_assistant:683]: Response: "23.4 degrees"
[11:15:44][D][voice_assistant:627]: Event Type: 8
[11:15:44][D][voice_assistant:703]: Response URL: "http://192.168.1.30:8123/api/tts_proxy/afd110e89ef34b16462957981ac054d5488b91b6_en-us_4c24684418_tts.home_assistant_cloud.mp3"
[11:15:44][D][voice_assistant:504]: State changed from AWAITING_RESPONSE to STREAMING_RESPONSE
[11:15:44][D][voice_assistant:510]: Desired state set to STREAMING_RESPONSE
[11:15:44][D][media_player:061]: 'voice-buero' - Setting
[11:15:44][D][media_player:068]: Media URL: http://192.168.1.30:8123/api/tts_proxy/afd110e89ef34b16462957981ac054d5488b91b6_en-us_4c24684418_tts.home_assistant_cloud.mp3
[11:15:44][D][media_player:074]: Announcement: yes
[11:15:44][D][adf_media_player:057]: Got control call in state IDLE
[11:15:44][D][adf_media_player:058]: req_track stream uri: http://192.168.1.30:8123/api/tts_proxy/afd110e89ef34b16462957981ac054d5488b91b6_en-us_4c24684418_tts.home_assistant_cloud.mp3
[11:15:44][D][esp_adf_pipeline:060]: Starting request, current state STOPPED
[11:15:44][D][light:036]: 'top_led' Setting:
[11:15:44][D][light:059]: Red: 20%, Green: 100%, Blue: 0%
[11:15:44][D][light:109]: Effect: 'speaking'
[11:15:44][D][voice_assistant:627]: Event Type: 2
[11:15:44][D][voice_assistant:717]: Assist Pipeline ended
[11:15:44][D][esp_adf_pipeline:448]: [MediaPlayer] Pipeline changed from STOPPED to PREPARING. (REQ: 0)
[11:15:44][I][adf_media_player:192]: got new pipeline state: 3, while in MP state IDLE
[11:15:44][D][adf_i2s_out:141]: Set final i2s settings: 16000
[11:15:44][D][esp_audio_processors:124]: Current settings: SRC: rate: 24000, ch: 1 bits: 16, DST: rate: 16000, ch: 1, bits 16
[11:15:44][I][adf_media_player:256]: current mp state: ANNOUNCING
[11:15:44][I][adf_media_player:257]: anouncement: yes
[11:15:44][I][adf_media_player:258]: play_intent: false
[11:15:44][I][adf_media_player:259]: current_uri_: false
[11:15:44][D][esp_audio_sources:140]: stream uri: http://192.168.1.30:8123/api/tts_proxy/afd110e89ef34b16462957981ac054d5488b91b6_en-us_4c24684418_tts.home_assistant_cloud.mp3
[11:15:44][D][adf_audio_element:108]: Preparing [http]...
[11:15:44][D][adf_audio_element:108]: Preparing [decoder]...
[11:15:44][D][adf_audio_element:108]: Preparing [resampler]...
[11:15:44][D][adf_audio_element:108]: Preparing [i2s_out]...
[11:15:44][D][adf_audio_element:165]: Resuming [http]...
[11:15:44][D][adf_audio_element:172]: [http] Sending resume command.
[11:15:44][D][adf_audio_element:165]: Resuming [decoder]...
[11:15:44][D][adf_audio_element:172]: [decoder] Sending resume command.
[11:15:44][D][esp-idf:000][decoder]: I (1062893) AUDIO_ELEMENT: [decoder] AEL_MSG_CMD_RESUME,state:1
[11:15:44][D][adf_audio_element:191]: [http] Checking State, got 79
[11:15:44][D][adf_audio_element:191]: [decoder] Checking State, got 79
[11:15:44][D][binary_sensor:036]: 'volume_up': Sending state OFF
[11:15:44][D][light:036]: 'right_led' Setting:
[11:15:44][D][light:047]: State: OFF
[11:15:44][D][light:085]: Transition length: 0.1s
[11:15:44][I][esp_audio_sources:033][http]: Receive http event: 2
[11:15:44][I][esp_audio_sources:033][http]: Receive http event: 4
[11:15:44][D][esp-idf:000][http]: I (1062972) HTTP_CLIENT: Body received in fetch header state, 0x3fcc81eb, 1841
[11:15:44][D][esp-idf:000][http]: I (1062976) HTTP_STREAM: total_bytes=17544
[11:15:44][I][HTTPStreamReader:230]: Codec Format reported: 3.
[11:15:44][I][HTTPStreamReader:240]: [ * ] Receive music info from decoder, sample_rates=24000, bits=16, ch=1
[11:15:44][I][HTTPStreamReader:243]: [ * ] Receive music info from decoder, codec_fmt=3, bps=48000, duration=0, bytes=-1128
[11:15:44][D][adf_i2s_out:141]: Set final i2s settings: 16000
[11:15:44][D][esp_audio_processors:124]: Current settings: SRC: rate: 24000, ch: 1 bits: 16, DST: rate: 16000, ch: 1, bits 16
[11:15:44][D][adf_audio_element:108]: Preparing [http]...
[11:15:44][D][adf_audio_element:108]: Preparing [decoder]...
[11:15:44][D][esp-idf:000][decoder]: W (1063025) AUDIO_ELEMENT: OUT-[decoder] AEL_IO_ABORT
[11:15:44][D][esp-idf:000][decoder]: W (1063029) MP3_DECODER: output aborted -3
[11:15:44][D][esp-idf:000][decoder]: I (1063034) MP3_DECODER: Closed
[11:15:45][D][esp_audio_sources:193]: Preparation done!
[11:15:45][D][esp_adf_pipeline:342]: wait for preparation, done
[11:15:45][D][esp_adf_pipeline:448]: [MediaPlayer] Pipeline changed from PREPARING to STARTING. (REQ: 0)
[11:15:45][I][adf_media_player:192]: got new pipeline state: 5, while in MP state ANNOUNCING
[11:15:45][I][adf_media_player:256]: current mp state: ANNOUNCING
[11:15:45][I][adf_media_player:257]: anouncement: yes
[11:15:45][I][adf_media_player:258]: play_intent: false
[11:15:45][I][adf_media_player:259]: current_uri_: false
[11:15:45][D][light:036]: 'top_led' Setting:
[11:15:45][D][light:051]: Brightness: 60%
[11:15:45][D][light:059]: Red: 100%, Green: 0%, Blue: 100%
[11:15:45][D][light:109]: Effect: 'listening_ww'
[11:15:45][D][adf_audio_element:165]: Resuming [http]...
[11:15:45][D][adf_audio_element:172]: [http] Sending resume command.
[11:15:45][D][adf_audio_element:165]: Resuming [decoder]...
[11:15:45][D][adf_audio_element:172]: [decoder] Sending resume command.
[11:15:45][D][adf_audio_element:165]: Resuming [resampler]...
[11:15:45][D][adf_audio_element:172]: [resampler] Sending resume command.
[11:15:45][D][esp-idf:000][resampler]: I (1063109) AUDIO_ELEMENT: [resampler] AEL_MSG_CMD_RESUME,state:1
[11:15:45][D][adf_audio_element:191]: [resampler] Checking State, got 79
[11:15:45][D][esp-idf:000][resampler]: I (1063156) RSP_FILTER: sample rate of source data : 24000, channel of source data : 1, sample rate of destination data : 16000, channel of destination data : 1
[11:15:45][I][esp_adf_pipeline:132]: [ resampler ] status: 12
[11:15:45][I][HTTPStreamReader:230]: Codec Format reported: 3.
[11:15:45][I][esp_adf_pipeline:132]: [ http ] status: 12
[11:15:45][I][esp_adf_pipeline:132]: [ decoder ] status: 12
[11:15:45][I][HTTPStreamReader:240]: [ * ] Receive music info from decoder, sample_rates=24000, bits=16, ch=1
[11:15:45][I][HTTPStreamReader:243]: [ * ] Receive music info from decoder, codec_fmt=3, bps=48000, duration=0, bytes=-1128
[11:15:45][D][micro_wake_word:178]: State changed from IDLE to START_MICROPHONE
[11:15:45][D][micro_wake_word:116]: Starting Microphone
[11:15:45][D][esp_adf_pipeline.microphone:025]: start request while ine state 0
[11:15:45][D][esp_adf_pipeline:060]: Starting request, current state STOPPED
[11:15:45][D][micro_wake_word:178]: State changed from START_MICROPHONE to STARTING_MICROPHONE
[11:15:45][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from STOPPED to PREPARING. (REQ: 0)
[11:15:45][D][adf_audio_element:108]: Preparing [i2s_in]...
[11:15:45][D][adf_audio_element:108]: Preparing [pcm_reader]...
[11:15:45][D][esp_adf_pipeline:342]: wait for preparation, done
[11:15:45][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from PREPARING to STARTING. (REQ: 0)
[11:15:45][D][adf_audio_element:165]: Resuming [i2s_in]...
[11:15:45][D][adf_audio_element:172]: [i2s_in] Sending resume command.
[11:15:45][D][esp-idf:000][i2s_in]: I (1063326) AUDIO_ELEMENT: [i2s_in] AEL_MSG_CMD_RESUME,state:1
[11:15:45][D][adf_audio_element:191]: [i2s_in] Checking State, got 78
[11:15:45][I][esp_adf_pipeline:132]: [ i2s_in ] status: 12
[11:15:45][D][adf_audio_element:191]: [pcm_reader] Checking State, got 65
[11:15:45][D][esp_adf_pipeline:448]: [ADFMicrophone] Pipeline changed from STARTING to RUNNING. (REQ: 0)
[11:15:45][D][micro_wake_word:178]: State changed from STARTING_MICROPHONE to DETECTING_WAKE_WORD
[11:15:45][D][light:036]: 'top_led' Setting:
[11:15:45][D][light:051]: Brightness: 60%
[11:15:45][D][light:059]: Red: 100%, Green: 0%, Blue: 100%
[11:15:45][D][light:085]: Transition length: 0.1s
[11:15:46][D][esp-idf:000][http]: W (1064649) HTTP_STREAM: No more data,errno:0, total_bytes:17544, rlen = 0
Flavor
MicroWakeWord
Checklist
Describe the issue
I just updated one of my satellites with the latest fix for the too loud or too silent bug. Since then even when I "disable" the fix, I got issues that the audio response take very long.
This is what I see in the log:
Issue is that, the audio response after the first response (reboot) or after a ceratin amount of time (1-2 minutes), is hanging. If I leave the satellite alone the response is coming like 15-30 seconds afterwards. But I can force the response when I just press one of the volume buttons.
I can only think that there is something with the libraries and not the code itself here, because there was nothing changed since my last update. ESPHome version is 2024.6.6
Reproduction steps
Debug logs