Playing a Mp3 File with a voice Command and a automation ====> ESP Crashes #36
Comments
|
I also noticed some issues when trying to trigger a mp3 stream from a voice command. Actually there was an issue of simultaneously trying to play the tts response message and the requested audio stream. I re-wrote some of the code to prevent this. You can try if this also fixes your issue: - source:
type: git
url: https://github.com/gnumpi/esphome_audio
ref: dev-next
components: [ adf_pipeline, i2s_audio ] |
i give it a try, now when i start a mp3 stream over voice he says something unreconizeable (i think he says "done" but my language is german) but plays nothing. when i trigger the play command when assist is in idle the LOG says something like got new pipeline state: 6, while in MP state PLAYING but when i trigger it over voice there is nothing like this. here is the log ` [20:24:38][D][esp-idf:000]: I (263816) I2S: DMA Malloc info, datalen=blocksize=512, dma_buf_count=4 [20:24:38][D][i2s_audio:072]: Installing driver : yes [20:24:38][D][esp-idf:000]: I (263846) AUDIO_PIPELINE: link el->rb, el:0x3d8325dc, tag:decoder, rb:0x3d833980 [20:24:38][D][esp_adf_pipeline:503]: Setting up event listener. [20:24:38][D][esp-idf:000]: I (264028) AUDIO_ELEMENT: [http-0x3d8263a4] Element task created [20:24:38][D][adf_audio_element:108]: Preparing [decoder]... [20:24:39][D][esp-idf:000]: I (264049) AUDIO_ELEMENT: [decoder-0x3d8325dc] Element task created [20:24:39][D][media_player:059]: 's3-dev_media_player' - Setting [20:24:39][D][light:036]: 'Status led' Setting: [20:24:39][D][esp-idf:000]: I (264173) MP3_DECODER: MP3 opened [20:24:39][D][esp-idf:000]: I (264348) HTTP_CLIENT: Body received in fetch header state, 0x3fccbae1, 1671 [20:24:39][D][esp-idf:000]: I (264351) HTTP_STREAM: total_bytes=0 [20:24:39][I][HTTPStreamReader:192]: [ * ] Receive music info from mp3 decoder, sample_rates=48000, bits=16, ch=2 [20:24:39][D][esp-idf:000]: W (264385) MP3_DECODER: output aborted -3 [20:24:39][I][adf_media_player:226]: current mp state: PLAYING [20:24:39][I][HTTPStreamReader:192]: [ * ] Receive music info from mp3 decoder, sample_rates=22050, bits=16, ch=1 [20:24:39][D][esp-idf:000]: I (264719) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0 [20:24:39][I][esp_adf_pipeline:135]: [ http ] status: 15 [20:24:40][D][esp-idf:000]: I (265550) MP3_DECODER: Closed [20:24:40][I][esp_adf_pipeline:135]: [ decoder ] status: 15 [20:24:40][I][esp_adf_pipeline:135]: [ i2s_out ] status: 15 [20:24:40][D][esp-idf:000]: W (265922) AUDIO_ELEMENT: [http] Element has not create when AUDIO_ELEMENT_TERMINATE [20:24:40][D][esp-idf:000]: W (265930) AUDIO_ELEMENT: [decoder] Element has not create when AUDIO_ELEMENT_TERMINATE [20:24:40][D][esp-idf:000]: W (265950) AUDIO_ELEMENT: [i2s_out] Element has not create when AUDIO_ELEMENT_TERMINATE [20:24:40][D][esp-idf:000]: I (265961) I2S: DMA queue destroyed [20:24:40][D][esp_adf_pipeline:444]: [MediaPlayer] Pipeline changed from DESTROYING to UNINITIALIZED. (REQ: 1) [20:24:43][D][i2s_audio:072]: Installing driver : yes [20:24:43][D][esp_adf_pipeline:503]: Setting up event listener. [20:24:43][D][adf_audio_element:108]: Preparing [pcm_reader]... [20:24:43][D][esp_adf_pipeline:345]: wait for preparation, done [20:24:43][D][adf_audio_element:191]: [i2s_in] Checking State, got 78 |
|
have you seen my feedback to the new version in "dev-next" above? |
|
I am sorry, but playing music from voice commands is not supported until esphome/esphome#6691 got merged. |
Okay, I'm not familiar with this, what are the chances of it being merged? and when is something like this usually merged? Thank You |
Actually, I don't know. There are quite a few PR for esphome, so the maintainers need to have their priorities and order of checking them. As this PR is mainly related to the ADF-pipeline which is only an external component for now, I guess it's not on their highest priority. Maybe you want to give it a try: external_components:
- source:
type: git
url: https://github.com/gnumpi/esphome
ref: adf-mods
components: [ api, media_player, speaker, voice_assistant ]
- source:
type: git
url: https://github.com/gnumpi/esphome_audio
ref: dev-next
components: [ adf_pipeline, i2s_audio ]
|
|
I also found a pretty reliable way to make it crash: basically playing a short mp3 on wake word detect and then starting VA. Even with delay and wait for done I can not make this work anyway in a reliable way I am using the onju voice config basically, with these modifications: external_components:
- source:
type: git
url: https://github.com/gnumpi/esphome_audio
#ref: d957129e0f37d622dd6e0efb2400bf2c9582a35c # main (high pitch issue)
ref: a8f66cbcb9ad96c71904225d0ee0e89641223247 #dev-next
components: [adf_pipeline, i2s_audio]
- source:
type: git
url: https://github.com/gnumpi/esphome
ref: 2044c7e4d4506b840dd2978d2fce5e455d304627 # adf-mods
components: [api, media_player, speaker, voice_assistant]
micro_wake_word:
model: okay_nabu
probability_cutoff: 0.5
on_wake_word_detected:
# - if:
# condition: media_player.is_playing
# then:
# - media_player.pause
- logger.log: "WAKEWORD!#################################"
- media_player.play_media:
id: onju_out
media_url: "http://192.168.0.244:8000/beep.mp3"
#media_url: "https://homeserver.bachi:8123/local/beep/beep.mp3"
- delay: 250ms
- wait_until:
media_player.is_idle: onju_out
- delay: 250ms
- logger.log: "DONE playing #####################"
- voice_assistant.start:
wake_word: !lambda return wake_word; |
|
Hey, thx for reporting your issue! Please, don't use the adf-mods anymore. All the necessary parts are already merged into the current ESPHome version. Can you confirm that your issue still exists with the latest dev-next commit and without the second external component in your config? |
|
Hi @gnumpi Yes it does, a8f66cb is the latest dev-next commit I only added the adf-mods after starting to play arround so the issue exists in anycase... unfortunatly it is also not super easy to get the logs from the onju, as it just looses them when crashing when using network logging But the issue is fairly consistent |
|
ok, let me try to reproduce the error with my hardware then ... |
|
unfortunately I couldn't reproduce your error, it is just working fine here. I don't have an Onju though, but I am running an ESP32-S3 with similar settings, and also in duplex mode. |
|
Ok, it always works fine on the first try, then somehow hangs up... seems like it is not crashing anymore with my current config though... Here is my config and the logs of 3 attempts... notice I use encryption... Configuration
Logs
|
|
On the second try it still plays the beep but then does not start the VA pipeline anymore |
|
upgraded to 2024.6 now... still feels like any media_player interaction I perform in the on_wakeword part of the config crashes it.... |
|
Seems this is fine now after testing with dev-next and ESPHome 2024.7.3 ! Works good for me at least now :-) |
Hello,
When i try to play a mp3 file with a automation thats reacts to a spoken command, the esp crashes.
When i send it over Services it works well without crashes. When i trigger the command in the automation manually it works well too.
I think its a timing problem? because the assist is active?
the command is the same, in the automation and when i use services
service: media_player.play_media target: entity_id: media_player.v_assist_kitchen_esp32nr168_s3_dev_media_player data: media_content_type: music media_content_id: http://live-icy.gss.dr.dk/A/A12H.mp3here is the Crash and reboot when triggered over the animation and the spoken command.
`23:26:08][D][esp_adf_pipeline:302]: State changed from STOPPING to UNINITIALIZED
[23:26:08][D][voice_assistant:439]: State changed from STOPPING_MICROPHONE to AWAITING_RESPONSE
[23:26:08][D][voice_assistant:563]: Event Type: 4
[23:26:08][D][voice_assistant:591]: Speech recognised as: " Schalte das Radio an."
[23:26:08][D][voice_assistant:563]: Event Type: 5
[23:26:08][D][voice_assistant:596]: Intent started
[23:26:08][D][media_player:059]: 's3-dev_media_player' - Setting
[23:26:08][D][media_player:066]: Media URL: http://live-icy.gss.dr.dk/A/A12H.mp3
[23:26:08][D][adf_media_player:030]: Got control call in state 1
[23:26:08][D][esp_adf_pipeline:050]: Starting request, current state UNINITIALIZED
[23:26:08][D][esp-idf:000]: I (573009) MP3_DECODER: MP3 init
[23:26:08][D][esp-idf:000]: I (573021) I2S: DMA Malloc info, datalen=blocksize=512, dma_buf_count=4
[23:26:08][D][i2s_audio:072]: Installing driver : yes
[23:26:08][D][esp_adf_pipeline:358]: pipeline tag 0, http
[23:26:08][D][esp_adf_pipeline:358]: pipeline tag 1, decoder
[23:26:08][D][esp_adf_pipeline:358]: pipeline tag 2, i2s_out
[23:26:08][D][esp-idf:000]: I (573052) AUDIO_PIPELINE: link el->rb, el:0x3d8263a4, tag:http, rb:0x3d8268b0
[23:26:08][D][esp-idf:000]: I (573060) AUDIO_PIPELINE: link el->rb, el:0x3d82654c, tag:decoder, rb:0x3d8278f0
[23:26:08][D][esp_adf_pipeline:370]: Setting up event listener.
[23:26:08][D][esp_adf_pipeline:302]: State changed from UNINITIALIZED to PREPARING
[23:26:08][I][adf_media_player:135]: got new pipeline state: 1
[23:26:08][D][adf_i2s_out:127]: Set final i2s settings: 22050
[23:26:08][D][esp-idf:000]: I (573095) AUDIO_THREAD: The http task allocate stack on external memory
[23:26:08][D][esp-idf:000]: I (573101) AUDIO_ELEMENT: [http-0x3d8263a4] Element task created
[23:26:08][D][esp-idf:000]: I (573112) AUDIO_THREAD: The decoder task allocate stack on external memory
[23:26:08][D][esp-idf:000]: I (573121) AUDIO_ELEMENT: [decoder-0x3d82654c] Element task created
[23:26:09][D][esp-idf:000]: I (573123) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1
[23:26:09][D][esp-idf:000]: I (573132) AUDIO_ELEMENT: [decoder] AEL_MSG_CMD_RESUME,state:1
[23:26:09][D][esp_aud:000]:
ERROR Fatal error: protocol.data_received() call failed.
protocol: <aioesphomeapi._frame_helper.noise.APINoiseFrameHelper object at 0x7f25b25d7c10>
transport: <_SelectorSocketTransport fd=6 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
File "/usr/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_ready__data_received
self._protocol.data_received(data)
File "aioesphomeapi/_frame_helper/noise.py", line 136, in aioesphomeapi._frame_helper.noise.APINoiseFrameHelper.data_received
File "aioesphomeapi/_frame_helper/noise.py", line 163, in aioesphomeapi._frame_helper.noise.APINoiseFrameHelper.data_received
File "aioesphomeapi/_frame_helper/noise.py", line 319, in aioesphomeapi._frame_helper.noise.APINoiseFrameHelper._handle_frame
File "/usr/local/lib/python3.11/dist-packages/noise/state.py", line 74, in decrypt_with_ad
plaintext = self.cipher.decrypt(self.k, self.n, ad, ciphertext)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/dist-packages/noise/backends/default/ciphers.py", line 13, in decrypt
return self.cipher.decrypt(nonce=self.format_nonce(n), data=ciphertext, associated_data=ad)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "src/chacha20poly1305_reuseable/init.py", line 127, in chacha20poly1305_reuseable.ChaCha20Poly1305Reusable.decrypt
File "src/chacha20poly1305_reuseable/init.py", line 147, in chacha20poly1305_reuseable.ChaCha20Poly1305Reusable.decrypt
File "src/chacha20poly1305_reuseable/init.py", line 263, in chacha20poly1305_reuseable._decrypt_with_fixed_nonce_len
File "src/chacha20poly1305_reuseable/init.py", line 273, in chacha20poly1305_reuseable._decrypt_data
cryptography.exceptions.InvalidTag
WARNING v-assist-kitchen-esp32nr168 @ 192.168.0.157: Connection error occurred: v-assist-kitchen-esp32nr168 @ 192.168.0.157: Invalid encryption key: received_name=v-assist-kitchen-esp32nr168
INFO Processing unexpected disconnect from ESPHome API for v-assist-kitchen-esp32nr168 @ 192.168.0.157
WARNING Disconnected from API
INFO Successfully connected to v-assist-kitchen-esp32nr168 @ 192.168.0.157 in 0.009s
INFO Successful handshake with v-assist-kitchen-esp32nr168 @ 192.168.0.157 in 0.118s
[23:26:09][D][esp-idf:000]: I (573327) HTTP_CLIENT: Body received in fetch header state, 0x3fccbd99, 1152
[23:26:09][D][esp-idf:000]: I (573331) HTTP_STREAM: total_bytes=0
[23:26:12][D][esp_adf_pipeline:400]: Called deinit_all
[23:26:14][D][esp-idf:000]: W (578286) AUDIO_ELEMENT: [http-0x3d8263a4] Element task destroy timeout[2000]
[23:26:16][D][esp-idf:000]: W (580288) AUDIO_ELEMENT: [decoder-0x3d82654c] Element task destroy timeout[2000]
[23:26:16][D][esp-idf:000]: W (580290) AUDIO_ELEMENT: [i2s_out] Element has not create when AUDIO_ELEMENT_TERMINATE
[23:26:16][D][esp-idf:000]: I (580292) AUDIO_PIPELINE: audio_pipeline_unlinked
WARNING v-assist-kitchen-esp32nr168 @ 192.168.0.157: Connection error occurred: [Errno 104] Connection reset by peer
INFO Processing unexpected disconnect from ESPHome API for v-assist-kitchen-esp32nr168 @ 192.168.0.157
WARNING Disconnected from API
INFO Successfully connected to v-assist-kitchen-esp32nr168 @ 192.168.0.157 in 0.009s
INFO Successful handshake with v-assist-kitchen-esp32nr168 @ 192.168.0.157 in 0.099s
`
The text was updated successfully, but these errors were encountered: