Home Assistant Voice PE "The announcement pipeline's file reader encountered an error"

wildegnux · January 11, 2025, 11:19pm

I have home assistant running in docker. In the initial setup of the Voice PE I get the error " The voice assistant is unable to connect to Home Assistant". The link to documentation in the error points to the local network URL being incorrect, that is not the case here, the URL is valid, plain http and can be reached from the network the Voice PE is on. Logs indicate no connection issues.

The esphome logs from the device indicates issues reading an audio file from HA:

[23:46:51][E][nabu_media_player:305]: The announcement pipeline's file reader encountered an error.

Since the documentation for voice PE all seems to assume you’re running HAOS in some form pressed on and made sure to have the wyoming setup finished as well, thinking something could be missing there. So i have wyoming with piper, whisper and openwakeword set up. In Settings → Voice Assistants I have a voice assistant set up using my local piper/whisper and that works fine when interacting with it through the web ui. Still, after that being set up I get the same error when trying to set up the voice PE. What am I missing?

Error:

Voice Assistant config:

Device logs:

[23:46:42][D][esp-idf:000][update_task]: I (44032) esp-x509-crt-bundle: Certificate validated
[23:46:42]
[23:46:43][D][update:011][update_task]: 'Home Assistant Voice 096425' - Publishing:
[23:46:43][D][update:012][update_task]:   Current Version: 25.1.0
[23:46:43][D][update:015][update_task]:   Latest Version: 25.1.0
[23:46:43][D][update:018][update_task]:   Firmware URL: https://firmware.esphome.io/home-assistant-voice-pe/home-assistant-voice/25.1.0/home-assistant-voice-esp32s3.ota.bin
[23:46:43][D][update:021][update_task]:   Title: Nabu Casa.Home Assistant Voice PE
[23:46:43]* Bugfix: Avoid crashing when started without internet access
[23:46:43][D][update:026][update_task]:   Release URL: https://github.com/esphome/home-assistant-voice-pe/releases/tag/25.1.0
[23:46:46][D][light:036]: 'voice_assistant_leds' Setting:
[23:46:46][D][light:047]:   State: ON
[23:46:46][D][light:051]:   Brightness: 66%
[23:46:46][D][light:109]:   Effect: 'Replying'
[23:46:46][D][media_player:080]: 'Media Player' - Setting
[23:46:46][D][media_player:087]:   Media URL: http://192.168.1.67:8123/api/esphome/ffmpeg_proxy/a444e7685385ea130f4b9516893f4876/TfnRrLE851vzulEUND8_kg.flac
[23:46:46][D][media_player:093]:  Announcement: yes
[23:46:46][D][voice_assistant:515]: State changed from IDLE to STREAMING_RESPONSE
[23:46:46][D][voice_assistant:522]: Desired state set to STREAMING_RESPONSE
[23:46:46][D][ring_buffer:034]: Created ring buffer with size 48000
[23:46:46][D][ring_buffer:034]: Created ring buffer with size 48000
[23:46:46][D][ring_buffer:034]: Created ring buffer with size 65536
[23:46:46][D][ring_buffer:034]: Created ring buffer with size 65536
[23:46:46][D][power_supply:033]: Enabling power supply.
[23:46:46][D][nabu_media_player.pipeline:173]: Reading FLAC file type
[23:46:51][E][nabu_media_player:305]: The announcement pipeline's file reader encountered an error.
[23:46:51][D][voice_assistant:515]: State changed from STREAMING_RESPONSE to IDLE
[23:46:51][D][voice_assistant:522]: Desired state set to IDLE
[23:46:51][D][light:036]: 'voice_assistant_leds' Setting:
[23:46:51][D][light:047]:   State: OFF
[23:46:51][D][light:109]:   Effect: 'None'

ESPHome debug logs:

2025-01-11 23:46:40.733 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Sending UpdateCommandRequest: key: 2957754261
command: UPDATE_COMMAND_CHECK

2025-01-11 23:46:40.733 DEBUG (MainThread) [aioesphomeapi._frame_helper.base] home-assistant-voice-096425 @ 192.168.1.153: Sending frame: [0007760d95bf4bb01002]
2025-01-11 23:46:42.401 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Got message of type UpdateStateResponse: key: 2957754261
current_version: "25.1.0"
latest_version: "25.1.0"
title: "Nabu Casa.Home Assistant Voice PE"
release_summary: "## What\'s Changed\r\n* Bugfix: Avoid crashing when started without internet access"
release_url: "https://github.com/esphome/home-assistant-voice-pe/releases/tag/25.1.0"

2025-01-11 23:46:45.746 DEBUG (MainThread) [homeassistant.components.esphome.assist_satellite] Waiting for announcement to finished (message=, media_id=http://192.168.1.67:8123/api/assist_satellite/connection_test/fa6e7472fbdd6ad51a51eea2203e5828?authSig=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiIyNTc0OGZjYjI2NTc0NWViOWJjNmM3YjAwZWYxZWZmMiIsInBhdGgiOiIvYXBpL2Fzc2lzdF9zYXRlbGxpdGUvY29ubmVjdGlvbl90ZXN0L2ZhNmU3NDcyZmJkZDZhZDUxYTUxZWVhMjIwM2U1ODI4IiwicGFyYW1zIjpbXSwiaWF0IjoxNzM2NjM1NjA1LCJleHAiOjE3MzY3MjIwMDV9.YSb2memzED_omymcssnYDccL4k6LZVK6xnH243JMkRo)
2025-01-11 23:46:45.746 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] Media URL allowed by proxy: http://192.168.1.67:8123/api/assist_satellite/connection_test/fa6e7472fbdd6ad51a51eea2203e5828?authSig=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiIyNTc0OGZjYjI2NTc0NWViOWJjNmM3YjAwZWYxZWZmMiIsInBhdGgiOiIvYXBpL2Fzc2lzdF9zYXRlbGxpdGUvY29ubmVjdGlvbl90ZXN0L2ZhNmU3NDcyZmJkZDZhZDUxYTUxZWVhMjIwM2U1ODI4IiwicGFyYW1zIjpbXSwiaWF0IjoxNzM2NjM1NjA1LCJleHAiOjE3MzY3MjIwMDV9.YSb2memzED_omymcssnYDccL4k6LZVK6xnH243JMkRo
2025-01-11 23:46:45.746 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Sending VoiceAssistantAnnounceRequest: media_id: "http://192.168.1.67:8123/api/esphome/ffmpeg_proxy/a444e7685385ea130f4b9516893f4876/TfnRrLE851vzulEUND8_kg.flac"

2025-01-11 23:46:45.746 DEBUG (MainThread) [aioesphomeapi._frame_helper.base] home-assistant-voice-096425 @ 192.168.1.153: Sending frame: [0070770a6e687474703a2f2f3139322e3136382e312e36373a383132332f6170692f657370686f6d652f66666d7065675f70726f78792f61343434653736383533383565613133306634623935313638393366343837362f54666e52724c45383531767a756c45554e44385f6b672e666c6163]
2025-01-11 23:46:45.979 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Got message of type MediaPlayerStateResponse: key: 2232357057
state: MEDIA_PLAYER_STATE_PLAYING
volume: 0.499999881

2025-01-11 23:46:45.984 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] /usr/bin/ffmpeg -i http://192.168.1.67:8123/api/assist_satellite/connection_test/fa6e7472fbdd6ad51a51eea2203e5828?authSig=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiIyNTc0OGZjYjI2NTc0NWViOWJjNmM3YjAwZWYxZWZmMiIsInBhdGgiOiIvYXBpL2Fzc2lzdF9zYXRlbGxpdGUvY29ubmVjdGlvbl90ZXN0L2ZhNmU3NDcyZmJkZDZhZDUxYTUxZWVhMjIwM2U1ODI4IiwicGFyYW1zIjpbXSwiaWF0IjoxNzM2NjM1NjA1LCJleHAiOjE3MzY3MjIwMDV9.YSb2memzED_omymcssnYDccL4k6LZVK6xnH243JMkRo -f flac -ar 48000 -ac 1 -sample_fmt s16 -map_metadata -1 -vn -nostats pipe:
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output: ffmpeg version 6.1.2 Copyright (c) 2000-2024 the FFmpeg developers
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   built with gcc 14.2.0 (Alpine 14.2.0)
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   configuration: --prefix=/usr --disable-librtmp --disable-lzma --disable-static --disable-stripping --enable-avfilter --enable-gpl --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libdav1d --enable-libdrm --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libharfbuzz --enable-libmp3lame --enable-libopenmpt --enable-libopus --enable-libplacebo --enable-libpulse --enable-librav1e --enable-librist --enable-libsoxr --enable-libsrt --enable-libssh --enable-libtheora --enable-libv4l2 --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxcb --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-lto=auto --enable-lv2 --enable-openssl --enable-pic --enable-postproc --enable-pthreads --enable-shared --enable-vaapi --enable-vdpau --enable-version3 --enable-vulkan --optflags=-O3 --enable-libjxl --enable-libsvtav1 --enable-libvpl
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libavutil      58. 29.100 / 58. 29.100
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libavcodec     60. 31.102 / 60. 31.102
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libavformat    60. 16.100 / 60. 16.100
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libavdevice    60.  3.100 / 60.  3.100
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libavfilter     9. 12.100 /  9. 12.100
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libswscale      7.  5.100 /  7.  5.100
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libswresample   4. 12.100 /  4. 12.100
2025-01-11 23:46:46.016 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg[263] output:   libpostproc    57.  3.100 / 57.  3.100
2025-01-11 23:46:50.990 DEBUG (MainThread) [homeassistant.components.esphome.ffmpeg_proxy] ffmpeg transcoding cancelled
2025-01-11 23:46:51.016 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Got message of type MediaPlayerStateResponse: key: 2232357057
state: MEDIA_PLAYER_STATE_IDLE
volume: 0.499999881

2025-01-11 23:46:51.061 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Got message of type VoiceAssistantAnnounceFinished: success: true

2025-01-11 23:47:13.611 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Sending PingRequest: 
2025-01-11 23:47:13.611 DEBUG (MainThread) [aioesphomeapi._frame_helper.base] home-assistant-voice-096425 @ 192.168.1.153: Sending frame: [000007]
2025-01-11 23:47:13.709 DEBUG (MainThread) [aioesphomeapi.connection] home-assistant-voice-096425 @ 192.168.1.153: Got message of type PingResponse:

cayalag · January 12, 2025, 5:36pm

same thing for me… I’ve tried maaaany things (and spent hours on it) and no luck.

For the moment is a nice piece of decoration at home

wmaker · January 12, 2025, 6:57pm

While I am waiting to get my VPE, I’ve been tracking issues such as these, and I have mostly seen people having problems with local URL using https, and when people change to http it all works. Yours is the first I have seen using http.

Either way, I would suggest opening up an Issue here and see what they say.

wildegnux · January 13, 2025, 2:23pm

Opened an issue: Voice assistant setup fails with 'announcement pipeline's file reader' / ffmpeg_proxy error · Issue #288 · esphome/home-assistant-voice-pe · GitHub

wildegnux · January 21, 2025, 7:42pm

Solution found. It appears that during the VPE setup home assistant will connect to itself on the local network ip, which my firewall blocked. Docker is good at blowing holes in your firewall for inbound traffic to your containers, but not so much for outbound connections from your containers.
So for me the solution was to allow the traffic using ufw:

sudo ufw allow from 172.16.0.0/12 to 192.168.1.0/24 port 8123 proto tcp

Which works but might be a bit overly permissive. I’d prefer to narrow it down to the specific IP/range of my HA network and keep that dynamically updated (since docker could change the IPs around when restarting) but I don’t know of a good way to do that. But that part is definitely not a VPE or HA issue. So closing this as solved.