Mar 25 17:42:00 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 17:42:00 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 17:42:00 volumiokueche volumio[27876]: info: Streaming services startup Mar 25 17:42:00 volumiokueche volumio[27876]: info: Starting Streaming Daemon Mar 25 17:42:00 volumiokueche sudo[28261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:42:00 volumiokueche sudo[28261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:00 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 17:42:00 volumiokueche sudo[28261]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:00 volumiokueche volumio[27876]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:00 volumiokueche volumio[27876]: error: Cannot start Volumio Streaming Daemon Mar 25 17:42:00 volumiokueche volumio[27876]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:42:00 volumiokueche volumio[27876]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:42:00 volumiokueche volumio[27876]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:00 volumiokueche volumio[27876]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 17:42:01 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 305. Mar 25 17:42:01 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:01 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:01 volumiokueche go-librespot[28267]: go-librespot daemon starting... Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=debug msg="app state loaded" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=info msg="zeroconf server listening on port 34121" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=debug msg="obtained new client token: AAACVUvj+y4LmOtAKYzHp5nLSujiEDBcaVPw0GULz9VA1SiG7cILuJKNbkqRzXlYiWCOLcPgJy4lDJ5tHGVr55CgY0uhfnaxm1Bm8g+DuikaYCf6I++WU+EW4OaZ6SNRs+/bwV/hLCLMhRLCVjmyreRYwv889z7uAgXzlCyv3MxFdy4oCGwqZuQAzA1zBjpYAuITMA3VytfR/dytky2nR8cJ5zqM4w1i1stsoAdQ9J2kYZDZe2Y5sDo=" Mar 25 17:42:01 volumiokueche volumio[27876]: info: MyVolumio token set successfully Mar 25 17:42:01 volumiokueche volumio[27876]: info: MYVOLUMIO: Adding device Mar 25 17:42:01 volumiokueche volumio[27876]: info: MYVOLUMIO: Evaluating Server Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:01 volumiokueche go-librespot[28268]: time="2026-03-25T17:42:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:42:01 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:01 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:02 volumiokueche volumio[27876]: info: MyVolumio Plan changed: premium Mar 25 17:42:02 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 25 17:42:02 volumiokueche volumio[27876]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 17:42:02 volumiokueche volumio[27876]: info: Removing audio output: Mar 25 17:42:02 volumiokueche volumio[27876]: info: MYVOLUMIO: Adding device Mar 25 17:42:02 volumiokueche volumio[27876]: info: MYVOLUMIO: Evaluating Server Mar 25 17:42:02 volumiokueche volumio[27876]: info: Remote config written successfully Mar 25 17:42:02 volumiokueche volumio[27876]: info: Starting Tunnel 1 Mar 25 17:42:02 volumiokueche volumio[27876]: info: Starting Tunnel Connection Checker Mar 25 17:42:02 volumiokueche volumio[27876]: info: Completed starting MyVolumio Plugin Mar 25 17:42:02 volumiokueche volumio[27876]: info: MYVolumio Device enabled Mar 25 17:42:02 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 25 17:42:02 volumiokueche volumio[27876]: info: MyVolumio status changed Mar 25 17:42:02 volumiokueche volumio[27876]: info: Streaming services startup Mar 25 17:42:02 volumiokueche volumio[27876]: info: Starting Streaming Daemon Mar 25 17:42:02 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 25 17:42:02 volumiokueche sudo[28328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:42:02 volumiokueche sudo[28328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:02 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 25 17:42:02 volumiokueche sudo[28328]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:02 volumiokueche volumio[27876]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 25 17:42:02 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 25 17:42:03 volumiokueche sudo[28333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 25 17:42:03 volumiokueche sudo[28333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche sudo[28333]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche volumio[27876]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: MultiRoom plugin initialized Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: STOPPING SNAPCLIENT Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: Snap server stop Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: STOPPING volumioStreaming Mar 25 17:42:03 volumiokueche sudo[28350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 25 17:42:03 volumiokueche sudo[28350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche sudo[28352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 25 17:42:03 volumiokueche sudo[28352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 25 17:42:03 volumiokueche sudo[28357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 25 17:42:03 volumiokueche sudo[28357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche sudo[28356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 25 17:42:03 volumiokueche sudo[28356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche sudo[28357]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 25 17:42:03 volumiokueche sudo[28352]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 25 17:42:03 volumiokueche sudo[28350]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche sudo[28356]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 25 17:42:03 volumiokueche volumio[27876]: info: Preparing to generate the ALSA configuration file Mar 25 17:42:03 volumiokueche volumio[27876]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:03 volumiokueche volumio[27876]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 25 17:42:03 volumiokueche volumio[27876]: info: Reading ALSA contributions from plugins. Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: Removed streaming files Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: volumioStreaming STOPPED Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: SNAPSERVER STOPPED Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: SNAPCLIENT STOPPED Mar 25 17:42:03 volumiokueche volumio[27876]: error: Cannot start Volumio Streaming Daemon Mar 25 17:42:03 volumiokueche volumio[27876]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:42:03 volumiokueche volumio[27876]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:42:03 volumiokueche volumio[27876]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:03 volumiokueche volumio[27876]: info: Asound.conf file written Mar 25 17:42:03 volumiokueche sudo[28363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 25 17:42:03 volumiokueche sudo[28363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche sudo[28363]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche volumio[27876]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 25 17:42:03 volumiokueche volumio[27876]: info: Output device has changed, restarting MPD Mar 25 17:42:03 volumiokueche volumio[27876]: info: Output device has changed, restarting Shairport Sync Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:03 volumiokueche sudo[28369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:42:03 volumiokueche sudo[28369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche sudo[28369]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche sudo[28371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:42:03 volumiokueche sudo[28371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche volumio[27876]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: Pushing multiroomSync output for this device Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: Pushing multiroomSync output Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding audio output: Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding audio output: Mar 25 17:42:03 volumiokueche systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 17:42:03 volumiokueche volumio[27876]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding METAVOLUMIO REST API Endpoints Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Plugin smart_inputs disabled by user. Not starting Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 25 17:42:03 volumiokueche systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:42:03 volumiokueche systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:42:03 volumiokueche systemd[1]: mpd.service: Consumed 2.109s CPU time. Mar 25 17:42:03 volumiokueche systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:42:03 volumiokueche volumio[27876]: error: Hi Res Audio Failed Login: Missing Login Data Mar 25 17:42:03 volumiokueche systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:42:03 volumiokueche systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Mar 25 17:42:03 volumiokueche volumio[27876]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding TIDAL REST API Endpoints Mar 25 17:42:03 volumiokueche volumio[27876]: info: Stopping AccessToken refresher cron for QOBUZ Mar 25 17:42:03 volumiokueche volumio[27876]: info: AccessToken refresher cron started for QOBUZ Mar 25 17:42:03 volumiokueche volumio[27876]: info: Adding QOBUZ REST API Endpoints Mar 25 17:42:03 volumiokueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:42:03 volumiokueche systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:42:03 volumiokueche volumio[27876]: info: MPD Permissions set Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: [Metrics] CommandRouter: 22s 830.16ms Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::volumiosetStartupVolume Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::Close All Modals sent Mar 25 17:42:03 volumiokueche volumio[27876]: info: CoreCommandRouter::Close All Modals sent Mar 25 17:42:03 volumiokueche volumio[27876]: info: Starting Shairport Sync Mar 25 17:42:03 volumiokueche sudo[28393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:03 volumiokueche sudo[28393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:03 volumiokueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:42:03 volumiokueche systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:42:03 volumiokueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:03 volumiokueche systemd[1]: shairport-sync.service: Consumed 1.590s CPU time. Mar 25 17:42:03 volumiokueche sudo[28384]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 17:42:03 volumiokueche sudo[28384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 17:42:03 volumiokueche sudo[28384]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:03 volumiokueche sudo[28393]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:03 volumiokueche volumio[27876]: info: Shairport-Sync Started Mar 25 17:42:04 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 25 17:42:04 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 25 17:42:04 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 25 17:42:04 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 306. Mar 25 17:42:04 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:04 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:04 volumiokueche go-librespot[28416]: go-librespot daemon starting... Mar 25 17:42:04 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:04 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:04+01:00" level=debug msg="app state loaded" Mar 25 17:42:04 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:05 volumiokueche mpd[28397]: 2026-03-25T17:42:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:42:05 volumiokueche systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:42:05 volumiokueche sudo[28371]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:05 volumiokueche volumio[27876]: error: updateQueue error: null Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=info msg="zeroconf server listening on port 36939" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=debug msg="obtained new client token: AADQtmOa1Lmtx+RmPAu+Uiqc8ci7vVT5NUS7vrFvwvhJUTaxb2UoHS/fgwhCFiarAY5LJboF/tFpu1QM0mL9TK8L1Z+1lKLMAJpxOXyNuIKUWqJrEavS9VivzpEnP9ojTenl4e+7nPBd4V+EHdHSWic+750S9Glb3glF676/J+IuzU/CtBpnPx03J8eIxOLxwP9jECsi8YLGpMOZXSyKrDnGdfTsm1CSIOC9Fg4CD4EFbIhYEwrCJsg=" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=debug msg="completed challenge" Mar 25 17:42:05 volumiokueche go-librespot[28417]: time="2026-03-25T17:42:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:05 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:05 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:06 volumiokueche volumio[27876]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:06 volumiokueche volumio[27876]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:07 volumiokueche sudo[28432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 25 17:42:07 volumiokueche sudo[28432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:07 volumiokueche systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Mar 25 17:42:07 volumiokueche autossh[27786]: received signal to exit (15) Mar 25 17:42:07 volumiokueche systemd[1]: sshtunnel.service: Deactivated successfully. Mar 25 17:42:07 volumiokueche systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Mar 25 17:42:07 volumiokueche systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Mar 25 17:42:07 volumiokueche sudo[28432]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:07 volumiokueche volumio[27876]: info: Remote SSH Started Mar 25 17:42:07 volumiokueche autossh[28435]: port set to 0, monitoring disabled Mar 25 17:42:07 volumiokueche autossh[28435]: starting ssh (count 1) Mar 25 17:42:07 volumiokueche autossh[28435]: ssh child pid is 28438 Mar 25 17:42:07 volumiokueche volumio[27876]: info: Setting Geolocation for MyVolumio to eu4 Mar 25 17:42:07 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:07 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:07 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:07 volumiokueche volumio[27876]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 25 17:42:07 volumiokueche volumiossh-tunnel[28438]: Warning: Permanently added '[eu1.myvolumio.org]:2222' (RSA) to the list of known hosts. Mar 25 17:42:07 volumiokueche volumio[27876]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:07 volumiokueche volumio[27876]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:07 volumiokueche volumio[27876]: info: Setting Geolocation for MyVolumio to eu6 Mar 25 17:42:07 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:07 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:07 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:07 volumiokueche volumio[27876]: info: Successfully Added MyVolumio device Mar 25 17:42:07 volumiokueche volumio[27876]: info: Successfully Added MyVolumio device Mar 25 17:42:08 volumiokueche sudo[28440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:42:08 volumiokueche sudo[28440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:08 volumiokueche systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 17:42:08 volumiokueche systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 17:42:08 volumiokueche systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:08 volumiokueche systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:08 volumiokueche mpd_monitor.sh[28442]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 17:42:08 volumiokueche sudo[28440]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:08 volumiokueche volumio[27876]: info: Successfully started MPD Monitor Mar 25 17:42:08 volumiokueche volumio[27876]: info: Updating MyVolumio device info Mar 25 17:42:08 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:08 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:08 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:08 volumiokueche volumio[27876]: info: MRS: Getting audio outputs on start Mar 25 17:42:08 volumiokueche volumio[27876]: info: MRS: Requesting all other devices output Mar 25 17:42:08 volumiokueche volumio[27876]: info: Updating MyVolumio device info Mar 25 17:42:08 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:08 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:08 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:08 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 307. Mar 25 17:42:08 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:08 volumiokueche volumio[27876]: info: Successfully Updated MyVolumio device Mar 25 17:42:08 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:08 volumiokueche go-librespot[28446]: go-librespot daemon starting... Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=debug msg="app state loaded" Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:08 volumiokueche volumio[27876]: info: Successfully Updated MyVolumio device Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=info msg="zeroconf server listening on port 38167" Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=debug msg="obtained new client token: AACgR6rYpcElZBZEga+I9VoZkcGKd5korpJGvEK0g7SCQ56xbsaDliiX6fCv2XAHn3wF+WClvqHc4glPYBsAdpwdgSnhFreEeDg6CNqG9n/dbqm7vluUw1tFzetDTp0ArbmOUUqjcdu3vZuC0JBp6AKjajoJrn+oDpktMWMrRj8tisif94NTB2xcktyfKlmRapJuaZnoG/iKdGZwof9c3trf/SjfCL93BUH7AO8zfS3NFuHNYcch3k4=" Mar 25 17:42:08 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:09 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:09+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:09 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:09+01:00" level=debug msg="completed challenge" Mar 25 17:42:09 volumiokueche go-librespot[28447]: time="2026-03-25T17:42:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:09 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:09 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:09 volumiokueche volumio[27876]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:09 volumiokueche volumio[27876]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:10 volumiokueche volumio[27876]: info: BOOT COMPLETED Mar 25 17:42:11 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 105. Mar 25 17:42:11 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:11 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:11 volumiokueche upmpdcli[28454]: Could not open config: /tmp/upmpdcli.conf Mar 25 17:42:11 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:11 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 25 17:42:12 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 308. Mar 25 17:42:12 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:12 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:12 volumiokueche go-librespot[28469]: go-librespot daemon starting... Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="app state loaded" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:12 volumiokueche volumio[27876]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="new websocket client" Mar 25 17:42:12 volumiokueche volumio[27876]: info: Connection to go-librespot Websocket established Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=info msg="zeroconf server listening on port 39277" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="obtained new client token: AAAVouPOFTCnRiptypZCmWlRdqn6jWymT9DbqeVZoETxFBt+W3rxPpsUjc6croCvS37DEuFrD1wLISRIsIkaFo7ZMcFRH/VNEqAXjnpvVMBxcWtF+o18wdAV2bjtnxprJl/SChRp0znCuP9I8bAQVmLfnZnbdGeklizUU+FNesjjnGYmWwnfggaNpkqKJihVdU/Re/iJGLuwP87oeSBC8IpomQswVxOIWkvK1pYutKzS/D9Ccj33H6k=" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=debug msg="completed challenge" Mar 25 17:42:12 volumiokueche go-librespot[28470]: time="2026-03-25T17:42:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:12 volumiokueche volumio[27876]: info: Connection to go-librespot Websocket closed Mar 25 17:42:12 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:12 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:14 volumiokueche volumio[27876]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 25 17:42:14 volumiokueche volumio[27876]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 25 17:42:14 volumiokueche volumio[27876]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:14 volumiokueche volumio[27876]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:15 volumiokueche volumio[27876]: info: Getting Spotify volume Mar 25 17:42:15 volumiokueche volumio[27876]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:42:15 volumiokueche volumio[27876]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:15 volumiokueche volumio[27876]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 17:42:15 volumiokueche volumio[27876]: errno: -111, Mar 25 17:42:15 volumiokueche volumio[27876]: code: 'ECONNREFUSED', Mar 25 17:42:15 volumiokueche volumio[27876]: syscall: 'connect', Mar 25 17:42:15 volumiokueche volumio[27876]: address: '127.0.0.1', Mar 25 17:42:15 volumiokueche volumio[27876]: port: 9879, Mar 25 17:42:15 volumiokueche volumio[27876]: response: undefined Mar 25 17:42:15 volumiokueche volumio[27876]: } Mar 25 17:42:15 volumiokueche volumio[27876]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:42:15 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 309. Mar 25 17:42:15 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:15 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:15 volumiokueche go-librespot[28490]: go-librespot daemon starting... Mar 25 17:42:15 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:15 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:15+01:00" level=debug msg="app state loaded" Mar 25 17:42:15 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:15 volumiokueche sudo[28499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 17:41' Mar 25 17:42:15 volumiokueche sudo[28499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:15 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 17:42:15 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 17:42:15 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 17:42:15 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:15+01:00" level=info msg="zeroconf server listening on port 43745" Mar 25 17:42:15 volumiokueche sudo[28499]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:15 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 17:42:15 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 17:42:15 volumiokueche systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:16 volumiokueche systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 17:42:16 volumiokueche systemd[1]: volumio.service: Consumed 23.580s CPU time. Mar 25 17:42:16 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:16+01:00" level=debug msg="obtained new client token: AADpLKXJePZvP1AaHZmkpCm9jAfqTXXqQsDecI2prLqQNtMgk7BeWPrHTMIx0FH5SHbkupgy0avJIq5flANaktd57IRLHCkfaiiu+V+s8sDPBkv7hkWzEYbU6t0vwaWXViMtCc/MUtNMyGWwsUlZlH+ciEQCTCzYajzXvBKJG7fC+kpSFYAXutFmYnmTUfEJCj8+Wz7WicS8xBC7xRo2nyvzam4BieQ4BfAs3c1phwI9r9HIgle2ecg=" Mar 25 17:42:16 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:16 volumiokueche systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:42:16 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:16+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:16 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:16+01:00" level=debug msg="completed challenge" Mar 25 17:42:16 volumiokueche systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:42:16 volumiokueche go-librespot[28491]: time="2026-03-25T17:42:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:16 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:16 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:16 volumiokueche systemd[1]: volumio.service: Scheduled restart job, restart counter is at 44. Mar 25 17:42:16 volumiokueche systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:42:16 volumiokueche systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 17:42:16 volumiokueche systemd[1]: volumio.service: Consumed 23.580s CPU time. Mar 25 17:42:16 volumiokueche systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 17:42:16 volumiokueche systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:42:17 volumiokueche volumio[28512]: info: ------------------------------------------- Mar 25 17:42:17 volumiokueche volumio[28512]: info: ----- Volumio3 ---- Mar 25 17:42:17 volumiokueche volumio[28512]: info: ------------------------------------------- Mar 25 17:42:17 volumiokueche volumio[28512]: info: ----- System startup ---- Mar 25 17:42:17 volumiokueche volumio[28512]: info: ------------------------------------------- Mar 25 17:42:17 volumiokueche volumio[28512]: info: MYVOLUMIO Environment detected Mar 25 17:42:17 volumiokueche volumio[28512]: info: Plugin folders cleanup Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning into folder /volumio/app/plugins/ Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category audio_interface Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category miscellanea Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category music_service Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category plugins.json Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category system_controller Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category user_interface Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning into folder /data/plugins/ Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category music_service Mar 25 17:42:17 volumiokueche volumio[28512]: info: Scanning category user_interface Mar 25 17:42:17 volumiokueche volumio[28512]: info: Plugin folders cleanup completed Mar 25 17:42:17 volumiokueche volumio[28512]: info: ------------------------------------------- Mar 25 17:42:17 volumiokueche volumio[28512]: info: ----- Core plugins startup ---- Mar 25 17:42:17 volumiokueche volumio[28512]: info: ------------------------------------------- Mar 25 17:42:17 volumiokueche volumio[28512]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 17:42:17 volumiokueche volumio[28512]: info: Adding plugin upnp to MyMusic Plugins Mar 25 17:42:17 volumiokueche volumio[28512]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 17:42:17 volumiokueche volumio[28512]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 17:42:17 volumiokueche volumio[28512]: info: Loading plugins from folder /data/plugins/ Mar 25 17:42:17 volumiokueche volumio[28512]: info: Loading plugin "system"... Mar 25 17:42:17 volumiokueche volumio[28512]: info: Loading plugin "appearance"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "network"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Refreshing Cached IP Addresses Mar 25 17:42:18 volumiokueche sudo[28540]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 17:42:18 volumiokueche sudo[28540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:18 volumiokueche sudo[28542]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 17:42:18 volumiokueche sudo[28542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:18 volumiokueche sudo[28540]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "services"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "alsa_controller"... Mar 25 17:42:18 volumiokueche sudo[28542]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:18 volumiokueche sudo[28549]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 17:42:18 volumiokueche sudo[28549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:18 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "wizard"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "networkfs"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Starting Udev Watcher for removable devices Mar 25 17:42:18 volumiokueche volumio[28512]: info: Ignoring mount for partition: boot Mar 25 17:42:18 volumiokueche volumio[28512]: info: Ignoring mount for partition: volumio Mar 25 17:42:18 volumiokueche volumio[28512]: info: Ignoring mount for partition: volumio_data Mar 25 17:42:18 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "volumio_command_line_client"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Plugin upnp is not enabled Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "my_music"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "mpd"... Mar 25 17:42:18 volumiokueche volumio[28512]: info: Loading plugin "upnp_browser"... Mar 25 17:42:19 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 310. Mar 25 17:42:19 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:19 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:19 volumiokueche go-librespot[28573]: go-librespot daemon starting... Mar 25 17:42:19 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:19 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:19+01:00" level=debug msg="app state loaded" Mar 25 17:42:19 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:19 volumiokueche volumio[28512]: info: Starting UPNP Browser Mar 25 17:42:19 volumiokueche volumio[28512]: info: Loading plugin "alarm-clock"... Mar 25 17:42:19 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:19 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:19 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:19 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:19+01:00" level=info msg="zeroconf server listening on port 38975" Mar 25 17:42:19 volumiokueche volumio[28512]: info: Loading plugin "airplay_emulation"... Mar 25 17:42:19 volumiokueche volumio[28512]: info: Starting Shairport Sync Mar 25 17:42:19 volumiokueche volumio[28512]: info: Loading plugin "last_100"... Mar 25 17:42:19 volumiokueche volumio[28512]: info: Loading plugin "webradio"... Mar 25 17:42:19 volumiokueche volumio[28512]: info: Loading plugin "i2s_dacs"... Mar 25 17:42:19 volumiokueche volumio[28512]: info: I2S DAC not set, start Auto-detection Mar 25 17:42:19 volumiokueche volumio[28512]: info: Loading plugin "volumiodiscovery"... Mar 25 17:42:19 volumiokueche volumio[28512]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:19 volumiokueche volumio[28512]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:19 volumiokueche volumio[28512]: *** WARNING *** For more information see Mar 25 17:42:19 volumiokueche volumio[28512]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:19 volumiokueche volumio[28512]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:19 volumiokueche volumio[28512]: *** WARNING *** For more information see Mar 25 17:42:19 volumiokueche node[28512]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:19 volumiokueche node[28512]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:19 volumiokueche node[28512]: *** WARNING *** For more information see Mar 25 17:42:19 volumiokueche node[28512]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:19 volumiokueche node[28512]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:19 volumiokueche node[28512]: *** WARNING *** For more information see Mar 25 17:42:19 volumiokueche volumio[28512]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 17:42:19 volumiokueche volumio[28512]: info: Discovery: Started advertising with name: VolumioKueche Mar 25 17:42:19 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:42:19 volumiokueche volumio[28512]: info: Loading plugin "spop"... Mar 25 17:42:20 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:20+01:00" level=debug msg="obtained new client token: AACwhqA5uoERDzopEKh1pLnLPVCSgZjsnh70Xn0PtBNG088LZZWJxKQTEoxKbgkY/HiDNk8vCL5uohDG5wpacFW98GcKvO2sPb26gPiLKX9YxU+CaMEW8OzAzOz2UAnSXGXDQI/Xhfzm60LTJwaavhv5sfgjlni15WmbjAeIGPmi0LATbdeJvjGqjb1l85HZpwBgUMoMt6+q2F2yXUT5W10vn9siclvUnZgAZiKSgd15I/wvu8jlQWw=" Mar 25 17:42:20 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:20 volumiokueche go-librespot[28574]: time="2026-03-25T17:42:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:42:20 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:20 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:20 volumiokueche volumio[28512]: info: Loading plugin "now_playing"... Mar 25 17:42:20 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:20] [connect] Successful connection Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading plugin "outputs"... Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading plugin "albumart"... Mar 25 17:42:21 volumiokueche volumio[28512]: info: Plugin example_plugin is not enabled Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading plugin "inputs"... Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading plugin "updater_comm"... Mar 25 17:42:21 volumiokueche volumio[28512]: info: Plugin mpdemulation is not enabled Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading plugin "rest_api"... Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading plugin "websocket"... Mar 25 17:42:21 volumiokueche volumio[28512]: info: Starting Socket.io Server version 1.7.4 Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading plugin "touch_display"... Mar 25 17:42:21 volumiokueche volumio[28512]: info: Applying required configuration parameters for plugin touch_display Mar 25 17:42:21 volumiokueche volumio[28512]: info: Loading i18n strings for locale en Mar 25 17:42:21 volumiokueche volumio[28512]: Updating browse sources language Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:21 volumiokueche volumio[28584]: Forking 3 albumart workers Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::initPlayerControls Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: Express server listening on port 3000 Mar 25 17:42:21 volumiokueche volumio[28512]: [Metrics] WebUI: 4s 587.78ms Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::resetVolumioState Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::getcurrentVolume Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:21 volumiokueche volumio[28512]: info: Volumio Network Manager: Network status updated: 2 Mar 25 17:42:21 volumiokueche volumio[28512]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Mar 25 17:42:21 volumiokueche volumio[28512]: info: VolumeController:: Volume=86 Mute =false Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::pushState Mar 25 17:42:21 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::updateTrackBlock Mar 25 17:42:21 volumiokueche volumio[28512]: info: CorePlayQueue::getTrackBlock Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:42:21 volumiokueche sudo[28549]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:21 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774456940 101 Mar 25 17:42:21 volumiokueche volumio[28512]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Mar 25 17:42:21 volumiokueche volumio[28512]: info: Reloading queue from file Mar 25 17:42:21 volumiokueche volumio[28512]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Mar 25 17:42:21 volumiokueche volumio[28512]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Mar 25 17:42:21 volumiokueche volumio[28512]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::setRepeat false single undefined Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::pushState Mar 25 17:42:21 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::setRandom true Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreStateMachine::pushState Mar 25 17:42:21 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:42:21 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:21 volumiokueche volumio[28512]: info: Setting Device type: Raspberry PI Mar 25 17:42:22 volumiokueche volumio[28512]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 25 17:42:22 volumiokueche volumio[28512]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Mar 25 17:42:22 volumiokueche volumio[28512]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 25 17:42:22 volumiokueche volumio[28512]: info: Listing playlists Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetQueue Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreStateMachine::getQueue Mar 25 17:42:22 volumiokueche volumio[28512]: info: CorePlayQueue::getQueue Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetVisibleSources Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:22 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:22 volumiokueche volumio[28512]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Mar 25 17:42:22 volumiokueche volumio[28512]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Mar 25 17:42:22 volumiokueche volumio[28512]: info: Listing playlists Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetQueue Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreStateMachine::getQueue Mar 25 17:42:22 volumiokueche volumio[28512]: info: CorePlayQueue::getQueue Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetVisibleSources Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:22 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:22 volumiokueche volumio[28512]: info: VolumeController:: Volume=86 Mute =false Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreStateMachine::pushState Mar 25 17:42:22 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: adding 3d3a2849-45d3-428b-bde8-ecc2db686765 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: Found device VolumioBox Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: Connecting to remote: 192.168.2.168 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Completed loading Core Plugins Mar 25 17:42:22 volumiokueche volumio[28512]: info: Preparing to generate the ALSA configuration file Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: adding 0c0628ca-b4ec-475c-b4de-13a5df363f06 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: Found device VolumioKueche Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:22 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: this is already registered, 0c0628ca-b4ec-475c-b4de-13a5df363f06 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: Found device VolumioKueche Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:22 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Discovery: Connected to remote: 192.168.2.168 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Asound.conf file written Mar 25 17:42:22 volumiokueche sudo[28640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 25 17:42:22 volumiokueche sudo[28640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:22 volumiokueche sudo[28640]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:22 volumiokueche volumio[28512]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 25 17:42:22 volumiokueche volumio[28512]: info: Output device has changed, restarting MPD Mar 25 17:42:22 volumiokueche sudo[28646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:42:22 volumiokueche sudo[28646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:22 volumiokueche volumio[28512]: info: Output device has changed, restarting Shairport Sync Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:22 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:22 volumiokueche sudo[28646]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:22 volumiokueche sudo[28649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:42:22 volumiokueche sudo[28649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:22 volumiokueche volumio[28512]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:22 volumiokueche volumio[28512]: info: ___________ START PLUGINS ___________ Mar 25 17:42:22 volumiokueche volumio[28512]: info: ControllerMpd::onStart: Initializing MPD Mar 25 17:42:22 volumiokueche volumio[28512]: info: Creating MPD Configuration file Mar 25 17:42:22 volumiokueche systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 17:42:22 volumiokueche volumio[28596]: Starting albumart workers Mar 25 17:42:22 volumiokueche sudo[28656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:42:22 volumiokueche sudo[28656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:23 volumiokueche sudo[28656]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:23 volumiokueche volumio[28512]: info: [1774456943017] CoreMusicLibrary::Adding element Media Servers Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:23 volumiokueche systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:42:23 volumiokueche systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:42:23 volumiokueche systemd[1]: mpd.service: Consumed 1.499s CPU time. Mar 25 17:42:23 volumiokueche systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:42:23 volumiokueche systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:42:23 volumiokueche systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:42:23 volumiokueche sudo[28659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:42:23 volumiokueche sudo[28659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:23 volumiokueche volumio[28512]: info: UPNP Browser: Client initialized successfully Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:23 volumiokueche volumio[28512]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:23 volumiokueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:42:23 volumiokueche systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:42:23 volumiokueche systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:42:23 volumiokueche systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:42:23 volumiokueche systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:42:23 volumiokueche systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:42:23 volumiokueche systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:42:23 volumiokueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:42:23 volumiokueche volumio[28512]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:23 volumiokueche volumio[28512]: info: [1774456943189] CoreMusicLibrary::Adding element Last_100 Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:23 volumiokueche systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:23 volumiokueche volumio[28512]: info: [1774456943206] CoreMusicLibrary::Adding element Webradio Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:23 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 311. Mar 25 17:42:23 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:23 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:23 volumiokueche go-librespot[28673]: go-librespot daemon starting... Mar 25 17:42:23 volumiokueche volumio[28512]: info: Initializing BBC Radios Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="app state loaded" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:23 volumiokueche volumio[28595]: Starting albumart workers Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:23 volumiokueche sudo[28672]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 17:42:23 volumiokueche sudo[28672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 17:42:23 volumiokueche sudo[28672]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:23 volumiokueche volumio[28512]: info: Creating Spotify config file Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:23 volumiokueche volumio[28594]: Starting albumart workers Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=info msg="zeroconf server listening on port 36659" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="obtained new client token: AAA+YXmU8ezIMLtPuQVKHNgug3V88jx7oQhWMckje+yRYPgD7W075O5Hs/U9i/Raa7skhxijLOfEaAd+lIKy8cMzK700ztwIK/34KY/cWnnt4xe3NA9ZTEuFIVrIYELjoDxthkgU7xsZC7DVYtr2hj7w/eHz8KikzAcfavR30cado0IDC8KRKR2VAh2n0GUft0KRjU9LSFOas3u9I2mnDj+EuZHjuydyf0xgsQJYXsk/kf5T0mojRmI=" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=debug msg="completed challenge" Mar 25 17:42:23 volumiokueche go-librespot[28674]: time="2026-03-25T17:42:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:23 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:23 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:23 volumiokueche volumio[28512]: info: [now-playing] ConfigUpdater: config is up to date. Mar 25 17:42:23 volumiokueche volumio[28512]: info: Loading i18n strings for locale en Mar 25 17:42:23 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:23 volumiokueche volumio[28512]: info: Volumio Calling Home Mar 25 17:42:24 volumiokueche sudo[28698]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Mar 25 17:42:24 volumiokueche sudo[28698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:24 volumiokueche sudo[28698]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:24 volumiokueche sudo[28710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 25 17:42:24 volumiokueche sudo[28710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:24 volumiokueche sudo[28714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 25 17:42:24 volumiokueche sudo[28714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:24 volumiokueche sudo[28713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 25 17:42:24 volumiokueche sudo[28713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:24 volumiokueche systemd[1]: Reloading. Mar 25 17:42:24 volumiokueche volumio[28512]: info: [now-playing] Fetching API key... Mar 25 17:42:24 volumiokueche volumio[28512]: info: [now-playing] App is listening on port 4004. Mar 25 17:42:24 volumiokueche volumio[28512]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Mar 25 17:42:24 volumiokueche volumio[28512]: info: touch_display: Backlight interface detected. Mar 25 17:42:25 volumiokueche volumio[28512]: info: MPD Permissions set Mar 25 17:42:25 volumiokueche volumio[28512]: info: MPD Permissions set Mar 25 17:42:25 volumiokueche volumio[28512]: info: Volumio called home Mar 25 17:42:25 volumiokueche volumio[28512]: info: Spotify config file written Mar 25 17:42:25 volumiokueche sudo[28743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Mar 25 17:42:25 volumiokueche sudo[28743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:25 volumiokueche sudo[28743]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:25 volumiokueche sudo[28747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 17:42:25 volumiokueche sudo[28747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:25 volumiokueche volumio[28512]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:25 volumiokueche volumio[28512]: info: No need to fix Spotify hosts Mar 25 17:42:25 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:25 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:25 volumiokueche volumio[28512]: info: touch_display: IframeKeyboardBridge extension installed successfully Mar 25 17:42:25 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:25 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:25 volumiokueche mpd[28693]: decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:42:25 volumiokueche mpd[28693]: output: No 'audio_output' defined in config file Mar 25 17:42:25 volumiokueche volumio[28512]: info: touch_display: Raspberry Pi Foundation touch screen detected. Mar 25 17:42:25 volumiokueche volumio[28512]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 25 17:42:25 volumiokueche volumio[28512]: SPOTIFY: BQCA7XH4hPMBIgiG8O5JpWuk6WBKTHQXhaV6tKPLdrJmkDbh7piQK0E-MKci950EVLVe0TWJZQ0iJ5WESWDIchtYQUZGmFgPjjxpJCH8hpgZ7ZufyTqUQNxm-DojrdKS5sIrI3sdVGoj7tYrV4JH-enNZcBM6n93r1ORBZvX93D82LM5-AuUyoaUOjuYQRLQ54_LOE4RXI5JwhCL12TF4Ju-WyErnfi6hOGHyK622SpURJdeqR33XUR4eaOwuW1HwxR_XtoMkr1r4i568y6_mHrZF-CPRB-q Mar 25 17:42:25 volumiokueche volumio[28512]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 25 17:42:25 volumiokueche volumio[28512]: info: New Spotify access token = BQCA7XH4hPMBIgiG8O5JpWuk6WBKTHQXhaV6tKPLdrJmkDbh7piQK0E-MKci950EVLVe0TWJZQ0iJ5WESWDIchtYQUZGmFgPjjxpJCH8hpgZ7ZufyTqUQNxm-DojrdKS5sIrI3sdVGoj7tYrV4JH-enNZcBM6n93r1ORBZvX93D82LM5-AuUyoaUOjuYQRLQ54_LOE4RXI5JwhCL12TF4Ju-WyErnfi6hOGHyK622SpURJdeqR33XUR4eaOwuW1HwxR_XtoMkr1r4i568y6_mHrZF-CPRB-q Mar 25 17:42:25 volumiokueche volumio[28512]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 25 17:42:25 volumiokueche mpd[28693]: output: Successfully detected a sndio audio device Mar 25 17:42:25 volumiokueche mpd[28693]: zeroconf: No global port, disabling zeroconf Mar 25 17:42:25 volumiokueche volumio[28512]: info: Starting Shairport Sync Mar 25 17:42:25 volumiokueche sudo[28766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Mar 25 17:42:25 volumiokueche sudo[28766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:25 volumiokueche sudo[28766]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:25 volumiokueche sudo[28770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Mar 25 17:42:25 volumiokueche sudo[28770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:25 volumiokueche sudo[28770]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:25 volumiokueche systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:42:25 volumiokueche sudo[28659]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:25 volumiokueche sudo[28768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 25 17:42:25 volumiokueche sudo[28768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:25 volumiokueche volumio[28512]: info: Starting Shairport Sync Mar 25 17:42:25 volumiokueche sudo[28768]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:25 volumiokueche sudo[28649]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:25 volumiokueche sudo[28714]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:25 volumiokueche volumio[28512]: info: Starting Shairport Sync Mar 25 17:42:25 volumiokueche systemd[1]: Reloading. Mar 25 17:42:25 volumiokueche sudo[28780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:25 volumiokueche sudo[28780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:25 volumiokueche sudo[28781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:25 volumiokueche sudo[28781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:25 volumiokueche sudo[28777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:25 volumiokueche sudo[28777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:26 volumiokueche volumio[28512]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 25 17:42:26 volumiokueche volumio[28512]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 25 17:42:26 volumiokueche volumio[28512]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Mar 25 17:42:26 volumiokueche volumio[28512]: info: touch_display: File permissions for backlight brightness control set. Mar 25 17:42:26 volumiokueche volumio[28512]: error: MPD error: The expression evaluated to a falsy value: Mar 25 17:42:26 volumiokueche volumio[28512]: assert.ok(self.idling) Mar 25 17:42:26 volumiokueche volumio[28512]: error: The expression evaluated to a falsy value: Mar 25 17:42:26 volumiokueche volumio[28512]: assert.ok(self.idling) Mar 25 17:42:26 volumiokueche volumio[28512]: error: updateQueue error: null Mar 25 17:42:26 volumiokueche volumio[28512]: info: MPD running with PID28693 Mar 25 17:42:26 volumiokueche volumio[28512]: ,establishing connection Mar 25 17:42:26 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:26 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:26 volumiokueche volumio[28512]: error: updateQueue error: null Mar 25 17:42:26 volumiokueche volumio[28512]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): Could not obtain API key Mar 25 17:42:26 volumiokueche volumio[28512]: SPOTIFY: User informations: {"country":"DE","display_name":"oradke","email":"oradke@outlook.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/oradke"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/oradke","id":"oradke","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee857bfaea58dba3bad8441935b4","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b827bfaea58dba3bad8441935b4","width":64}],"product":"premium","type":"user","uri":"spotify:user:oradke"} Mar 25 17:42:26 volumiokueche volumio[28512]: info: Spotify Successfully logged in Mar 25 17:42:26 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:26 volumiokueche volumio[28512]: info: [1774456946389] CoreMusicLibrary::Adding element Spotify Mar 25 17:42:26 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:26 volumiokueche volumio[28512]: Cannot find translation for source Spotify Mar 25 17:42:26 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:26 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:26 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:26 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:26 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 106. Mar 25 17:42:26 volumiokueche sudo[28713]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:26 volumiokueche volumio[28512]: info: touch_display: systemctl daemon-reload succeeded. Mar 25 17:42:26 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 312. Mar 25 17:42:26 volumiokueche sudo[28808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 25 17:42:26 volumiokueche sudo[28808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:26 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:27 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:27 volumiokueche go-librespot[28810]: go-librespot daemon starting... Mar 25 17:42:27 volumiokueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:42:27 volumiokueche sudo[28747]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:27 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:27 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:27 volumiokueche sudo[28808]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:27 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:27 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:27+01:00" level=debug msg="app state loaded" Mar 25 17:42:27 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:27 volumiokueche systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:42:27 volumiokueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:27 volumiokueche systemd[1]: shairport-sync.service: Consumed 1.704s CPU time. Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: Volumio Kiosk started. Mar 25 17:42:27 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:27 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:27 volumiokueche upmpdcli[28812]: Could not open config: /tmp/upmpdcli.conf Mar 25 17:42:27 volumiokueche volumio[28512]: info: Completed starting Core Plugins Mar 25 17:42:27 volumiokueche volumio[28512]: info: ------------------------------------------- Mar 25 17:42:27 volumiokueche volumio[28512]: info: ----- MyVolumio plugins startup ---- Mar 25 17:42:27 volumiokueche volumio[28512]: info: ------------------------------------------- Mar 25 17:42:27 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 17:42:27 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:27 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 25 17:42:27 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:27 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:27 volumiokueche sudo[28710]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 25 17:42:27 volumiokueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:27 volumiokueche sudo[28781]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:27 volumiokueche sudo[28777]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:27 volumiokueche sudo[28780]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:27 volumiokueche volumio[28512]: info: Shairport-Sync Started Mar 25 17:42:27 volumiokueche volumio[28512]: Error adding Membership: Error: addMembership EINVAL Mar 25 17:42:27 volumiokueche volumio[28512]: info: Shairport-Sync Started Mar 25 17:42:27 volumiokueche volumio[28512]: info: Shairport-Sync Started Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: X display number found: 0 Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: X display number found: 0 Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 25 17:42:27 volumiokueche volumio[28512]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:27 volumiokueche volumio[28512]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: X display number found: 0 Mar 25 17:42:27 volumiokueche volumio[28512]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 25 17:42:29 volumiokueche sudo[28865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:42:29 volumiokueche sudo[28865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:29 volumiokueche sudo[28868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:42:29 volumiokueche sudo[28868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:29 volumiokueche systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 17:42:29 volumiokueche systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 17:42:29 volumiokueche systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:29 volumiokueche systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:29 volumiokueche sudo[28865]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:29 volumiokueche mpd_monitor.sh[28870]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 17:42:29 volumiokueche volumio[28512]: info: Successfully started MPD Monitor Mar 25 17:42:29 volumiokueche systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 17:42:29 volumiokueche systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 17:42:29 volumiokueche systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:29 volumiokueche systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:29 volumiokueche sudo[28868]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:29 volumiokueche mpd_monitor.sh[28873]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 17:42:29 volumiokueche volumio[28512]: info: Successfully started MPD Monitor Mar 25 17:42:30 volumiokueche volumio[28512]: info: go-librespot daemon successfully initialized Mar 25 17:42:31 volumiokueche mpd[28693]: exception: No database Mar 25 17:42:31 volumiokueche mpd[28693]: exception: No database Mar 25 17:42:31 volumiokueche mpd[28693]: exception: No database Mar 25 17:42:31 volumiokueche volumio[28512]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=info msg="zeroconf server listening on port 43451" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=debug msg="obtained new client token: AABOcWlguuDrMJ56bRFOzLY54Om4KWAGO34YKBD/sFIHrlpKS/qtvddRo732zNCpZhaa1WZGK0myRn5r+murUxOHZ1Ecs3XMvvvorYF22Yvn4+9Xon2T0RllVEqdXiVE/Qu794NelwxUA0zT2JA91DaosBl6ApPI+fUGYsGKWPI6bYM/XkJgPYC87dmJF7YZutm0fH9R6PzU7RVGi2AUYnJh5g6aXcuDNUyQgy2o8Iuhikwl+KYEmjo=" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=debug msg="completed challenge" Mar 25 17:42:32 volumiokueche go-librespot[28811]: time="2026-03-25T17:42:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:32 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:32 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:33 volumiokueche volumio[28512]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:33 volumiokueche volumio[28512]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 17:42:35 volumiokueche volumio[28512]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 17:42:35 volumiokueche volumio[28512]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 17:42:35 volumiokueche volumio[28512]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 17:42:35 volumiokueche volumio[28512]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 17:42:35 volumiokueche volumio[28512]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 17:42:35 volumiokueche volumio[28512]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 17:42:35 volumiokueche volumio[28512]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 17:42:35 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 313. Mar 25 17:42:35 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:35 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:35 volumiokueche go-librespot[28878]: go-librespot daemon starting... Mar 25 17:42:35 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:35 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:35+01:00" level=debug msg="app state loaded" Mar 25 17:42:35 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 17:42:35 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:35 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:35 volumiokueche volumio[28512]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 17:42:35 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:35 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:35 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:35 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:35+01:00" level=info msg="zeroconf server listening on port 45607" Mar 25 17:42:35 volumiokueche volumio[28512]: info: MyVolumio login type: Token Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 17:42:35 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 17:42:36 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:36+01:00" level=debug msg="obtained new client token: AAB2le0e0SDGkh/lZVoBKZ2rgn5MpZSkJl/gNl4UAmd+HFeU6Mpf2zOqZE274k3mHHHEMHlhv3PfU+WJMo6p2d49NLL1L+LZmlp7Pdt1nKfXUWvbwJ1jwsF4NVFeTVPAz/8bgzrZpJBZiVRW3pScfcSMAKWwf23M2Y+/c31hkFC0cLxPxqjDU1ffggrbfl8VNb0tMf3GayZxewIV0MIExccjvPil8Kr2eYFBD36I/tGYLDuZntty" Mar 25 17:42:36 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:36 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:36+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:36 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:36+01:00" level=debug msg="completed challenge" Mar 25 17:42:36 volumiokueche go-librespot[28879]: time="2026-03-25T17:42:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:36 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:36 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:36 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 17:42:36 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 17:42:36 volumiokueche volumio[28512]: info: Streaming services startup Mar 25 17:42:36 volumiokueche volumio[28512]: info: Starting Streaming Daemon Mar 25 17:42:36 volumiokueche sudo[28888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:42:36 volumiokueche sudo[28888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:36 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 17:42:36 volumiokueche sudo[28888]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:36 volumiokueche volumio[28512]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:36 volumiokueche volumio[28512]: error: Cannot start Volumio Streaming Daemon Mar 25 17:42:36 volumiokueche volumio[28512]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:42:36 volumiokueche volumio[28512]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:42:36 volumiokueche volumio[28512]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:37 volumiokueche volumio[28512]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 17:42:37 volumiokueche volumio[28512]: info: MyVolumio token set successfully Mar 25 17:42:37 volumiokueche volumio[28512]: info: MYVOLUMIO: Adding device Mar 25 17:42:37 volumiokueche volumio[28512]: info: MYVOLUMIO: Evaluating Server Mar 25 17:42:37 volumiokueche volumio[28512]: info: MyVolumio Plan changed: premium Mar 25 17:42:37 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 25 17:42:37 volumiokueche volumio[28512]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 17:42:37 volumiokueche volumio[28512]: info: Removing audio output: Mar 25 17:42:37 volumiokueche volumio[28512]: info: MYVOLUMIO: Adding device Mar 25 17:42:37 volumiokueche volumio[28512]: info: MYVOLUMIO: Evaluating Server Mar 25 17:42:37 volumiokueche volumio[28512]: info: Remote config written successfully Mar 25 17:42:37 volumiokueche volumio[28512]: info: Starting Tunnel 1 Mar 25 17:42:37 volumiokueche volumio[28512]: info: Starting Tunnel Connection Checker Mar 25 17:42:37 volumiokueche volumio[28512]: info: Completed starting MyVolumio Plugin Mar 25 17:42:38 volumiokueche volumio[28512]: info: MYVolumio Device enabled Mar 25 17:42:38 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 25 17:42:38 volumiokueche volumio[28512]: info: MyVolumio status changed Mar 25 17:42:38 volumiokueche volumio[28512]: info: Streaming services startup Mar 25 17:42:38 volumiokueche volumio[28512]: info: Starting Streaming Daemon Mar 25 17:42:38 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 25 17:42:38 volumiokueche sudo[28933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:42:38 volumiokueche sudo[28933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:38 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 25 17:42:38 volumiokueche sudo[28933]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:38 volumiokueche volumio[28512]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 25 17:42:38 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 25 17:42:38 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 25 17:42:38 volumiokueche sudo[28951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 25 17:42:38 volumiokueche sudo[28951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:38 volumiokueche sudo[28951]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:38 volumiokueche volumio[28512]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 25 17:42:38 volumiokueche volumio[28512]: info: MRS: MultiRoom plugin initialized Mar 25 17:42:38 volumiokueche volumio[28512]: info: MRS: STOPPING SNAPCLIENT Mar 25 17:42:38 volumiokueche volumio[28512]: info: MRS: Snap server stop Mar 25 17:42:38 volumiokueche volumio[28512]: info: MRS: STOPPING volumioStreaming Mar 25 17:42:38 volumiokueche sudo[28968]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 25 17:42:38 volumiokueche sudo[28968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:38 volumiokueche sudo[28970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 25 17:42:38 volumiokueche sudo[28970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:38 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 25 17:42:38 volumiokueche sudo[28973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 25 17:42:38 volumiokueche sudo[28973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:38 volumiokueche sudo[28976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 25 17:42:38 volumiokueche sudo[28976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:39 volumiokueche sudo[28976]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 25 17:42:39 volumiokueche sudo[28968]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 25 17:42:39 volumiokueche sudo[28973]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche sudo[28970]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 25 17:42:39 volumiokueche volumio[28512]: info: Preparing to generate the ALSA configuration file Mar 25 17:42:39 volumiokueche volumio[28512]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 25 17:42:39 volumiokueche volumio[28512]: info: Reading ALSA contributions from plugins. Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: Removed streaming files Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: volumioStreaming STOPPED Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: SNAPSERVER STOPPED Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: SNAPCLIENT STOPPED Mar 25 17:42:39 volumiokueche volumio[28512]: error: Cannot start Volumio Streaming Daemon Mar 25 17:42:39 volumiokueche volumio[28512]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:42:39 volumiokueche volumio[28512]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:42:39 volumiokueche volumio[28512]: info: Asound.conf file written Mar 25 17:42:39 volumiokueche sudo[28981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 25 17:42:39 volumiokueche sudo[28981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:39 volumiokueche sudo[28981]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche volumio[28512]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 25 17:42:39 volumiokueche volumio[28512]: info: Output device has changed, restarting MPD Mar 25 17:42:39 volumiokueche volumio[28512]: info: Output device has changed, restarting Shairport Sync Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:39 volumiokueche sudo[28987]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:42:39 volumiokueche sudo[28987]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:39 volumiokueche sudo[28987]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche sudo[28989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:42:39 volumiokueche sudo[28989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:39 volumiokueche volumio[28512]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: Pushing multiroomSync output for this device Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: Pushing multiroomSync output Mar 25 17:42:39 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 314. Mar 25 17:42:39 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding audio output: Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding audio output: Mar 25 17:42:39 volumiokueche volumio[28512]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding METAVOLUMIO REST API Endpoints Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Plugin smart_inputs disabled by user. Not starting Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 25 17:42:39 volumiokueche volumio[28512]: error: Hi Res Audio Failed Login: Missing Login Data Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Mar 25 17:42:39 volumiokueche volumio[28512]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding TIDAL REST API Endpoints Mar 25 17:42:39 volumiokueche volumio[28512]: info: Stopping AccessToken refresher cron for QOBUZ Mar 25 17:42:39 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:39 volumiokueche systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 17:42:39 volumiokueche go-librespot[28998]: go-librespot daemon starting... Mar 25 17:42:39 volumiokueche volumio[28512]: info: AccessToken refresher cron started for QOBUZ Mar 25 17:42:39 volumiokueche volumio[28512]: info: Adding QOBUZ REST API Endpoints Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="app state loaded" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:39 volumiokueche volumio[28512]: info: MPD Permissions set Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:42:39 volumiokueche systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:42:39 volumiokueche systemd[1]: mpd.service: Consumed 2.112s CPU time. Mar 25 17:42:39 volumiokueche systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:42:39 volumiokueche systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:42:39 volumiokueche systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:42:39 volumiokueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:42:39 volumiokueche systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: [Metrics] CommandRouter: 22s 170.54ms Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::volumiosetStartupVolume Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::Close All Modals sent Mar 25 17:42:39 volumiokueche volumio[28512]: info: CoreCommandRouter::Close All Modals sent Mar 25 17:42:39 volumiokueche volumio[28512]: info: Starting Shairport Sync Mar 25 17:42:39 volumiokueche sudo[29018]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:39 volumiokueche sudo[29018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:39 volumiokueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:42:39 volumiokueche systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:42:39 volumiokueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:39 volumiokueche systemd[1]: shairport-sync.service: Consumed 1.597s CPU time. Mar 25 17:42:39 volumiokueche sudo[29014]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 17:42:39 volumiokueche sudo[29014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 17:42:39 volumiokueche sudo[29014]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:39 volumiokueche volumio[28512]: info: Initializing connection to go-librespot Websocket Mar 25 17:42:39 volumiokueche sudo[29018]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="new websocket client" Mar 25 17:42:39 volumiokueche volumio[28512]: info: Shairport-Sync Started Mar 25 17:42:39 volumiokueche volumio[28512]: info: Connection to go-librespot Websocket established Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=info msg="zeroconf server listening on port 36751" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="obtained new client token: AADz6TaUgnQFF5ZatH985MSCXKKdAmHEQMsjms9OLDthQPLXmliolCNKGQl7//BUSoWpTgY+dhlz81VEKPlI2XBJ8R91lqEJiByMRTOSqU+fxK1dpiuPpGJKGvMnf+REANzW4EyHouxP/+GL+JEnIF/FL830qljMWIcz4BA/UJc0vtHeJDqlUhQxIQXoR7HT5YvrEmKaQSZq2k0dw5NANXJ200tZ1O7mxhuG/hSgIB4OzwqwpHSXcCA=" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=debug msg="completed challenge" Mar 25 17:42:39 volumiokueche go-librespot[29002]: time="2026-03-25T17:42:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:39 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:39 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:39 volumiokueche volumio[28512]: info: Connection to go-librespot Websocket closed Mar 25 17:42:40 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 25 17:42:40 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 25 17:42:40 volumiokueche volumio[28512]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 25 17:42:40 volumiokueche mpd[29023]: 2026-03-25T17:42:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:42:40 volumiokueche systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:42:40 volumiokueche sudo[28989]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:40 volumiokueche volumio[28512]: error: updateQueue error: null Mar 25 17:42:42 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 107. Mar 25 17:42:42 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:42 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:42 volumiokueche upmpdcli[29043]: Could not open config: /tmp/upmpdcli.conf Mar 25 17:42:42 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:42 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 25 17:42:42 volumiokueche volumio[28512]: info: Getting Spotify volume Mar 25 17:42:42 volumiokueche volumio[28512]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:42:42 volumiokueche volumio[28512]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:42:42 volumiokueche volumio[28512]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 17:42:42 volumiokueche volumio[28512]: errno: -111, Mar 25 17:42:42 volumiokueche volumio[28512]: code: 'ECONNREFUSED', Mar 25 17:42:42 volumiokueche volumio[28512]: syscall: 'connect', Mar 25 17:42:42 volumiokueche volumio[28512]: address: '127.0.0.1', Mar 25 17:42:42 volumiokueche volumio[28512]: port: 9879, Mar 25 17:42:42 volumiokueche volumio[28512]: response: undefined Mar 25 17:42:42 volumiokueche volumio[28512]: } Mar 25 17:42:42 volumiokueche volumio[28512]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:42:43 volumiokueche sudo[29058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 17:41' Mar 25 17:42:43 volumiokueche sudo[29058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:43 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 315. Mar 25 17:42:43 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:43 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:43 volumiokueche go-librespot[29060]: go-librespot daemon starting... Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="app state loaded" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:43 volumiokueche sudo[29058]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:43 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 17:42:43 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 17:42:43 volumiokueche systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:43 volumiokueche kernel: bcm2835-audio bcm2835-audio: failed to close VCHI service connection (status=-11) Mar 25 17:42:43 volumiokueche systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 17:42:43 volumiokueche systemd[1]: volumio.service: Consumed 22.194s CPU time. Mar 25 17:42:43 volumiokueche systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:42:43 volumiokueche systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=info msg="zeroconf server listening on port 44311" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="obtained new client token: AACQ9XUN3JKukrgefXJdTqDH+Fo3rhn8RdxXKLBPjaKBqktUkhHw/jPGe5qNO+VCMPftrWI6YY2Y9xgoESY/9/Smfoq4oYYocJZLq0+I6e/FLP+GnFEKIZHefevWaNLARpX1sWC5qfw8Gqw/PW9Gzi+GoBei14cCETEvV4MKdc5kTFfr541W9229S+o9ttCE1b74NQO6Z3chtqunzX4TYSbhPw/7bg12ts0WQPYVaZ6C2izdOezXoKI=" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:43 volumiokueche systemd[1]: volumio.service: Scheduled restart job, restart counter is at 45. Mar 25 17:42:43 volumiokueche systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:42:43 volumiokueche systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 17:42:43 volumiokueche systemd[1]: volumio.service: Consumed 22.194s CPU time. Mar 25 17:42:43 volumiokueche systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=debug msg="completed challenge" Mar 25 17:42:43 volumiokueche systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:42:43 volumiokueche go-librespot[29061]: time="2026-03-25T17:42:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:43 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:43 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:44 volumiokueche volumio[29084]: info: ------------------------------------------- Mar 25 17:42:44 volumiokueche volumio[29084]: info: ----- Volumio3 ---- Mar 25 17:42:44 volumiokueche volumio[29084]: info: ------------------------------------------- Mar 25 17:42:44 volumiokueche volumio[29084]: info: ----- System startup ---- Mar 25 17:42:44 volumiokueche volumio[29084]: info: ------------------------------------------- Mar 25 17:42:45 volumiokueche volumio[29084]: info: MYVOLUMIO Environment detected Mar 25 17:42:45 volumiokueche volumio[29084]: info: Plugin folders cleanup Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning into folder /volumio/app/plugins/ Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category audio_interface Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category miscellanea Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category music_service Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category plugins.json Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category system_controller Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category user_interface Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning into folder /data/plugins/ Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category music_service Mar 25 17:42:45 volumiokueche volumio[29084]: info: Scanning category user_interface Mar 25 17:42:45 volumiokueche volumio[29084]: info: Plugin folders cleanup completed Mar 25 17:42:45 volumiokueche volumio[29084]: info: ------------------------------------------- Mar 25 17:42:45 volumiokueche volumio[29084]: info: ----- Core plugins startup ---- Mar 25 17:42:45 volumiokueche volumio[29084]: info: ------------------------------------------- Mar 25 17:42:45 volumiokueche volumio[29084]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 17:42:45 volumiokueche volumio[29084]: info: Adding plugin upnp to MyMusic Plugins Mar 25 17:42:45 volumiokueche volumio[29084]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 17:42:45 volumiokueche volumio[29084]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 17:42:45 volumiokueche volumio[29084]: info: Loading plugins from folder /data/plugins/ Mar 25 17:42:45 volumiokueche volumio[29084]: info: Loading plugin "system"... Mar 25 17:42:45 volumiokueche volumio[29084]: info: Loading plugin "appearance"... Mar 25 17:42:45 volumiokueche volumio[29084]: info: Loading plugin "network"... Mar 25 17:42:45 volumiokueche volumio[29084]: info: Refreshing Cached IP Addresses Mar 25 17:42:45 volumiokueche sudo[29112]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 17:42:45 volumiokueche sudo[29112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:45 volumiokueche sudo[29112]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:45 volumiokueche sudo[29114]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 17:42:45 volumiokueche volumio[29084]: info: Loading plugin "services"... Mar 25 17:42:45 volumiokueche sudo[29114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:45 volumiokueche volumio[29084]: info: Loading plugin "alsa_controller"... Mar 25 17:42:45 volumiokueche sudo[29114]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:45 volumiokueche sudo[29122]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 17:42:46 volumiokueche sudo[29122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:46 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:46 volumiokueche volumio[29084]: info: Loading plugin "wizard"... Mar 25 17:42:46 volumiokueche volumio[29084]: info: Loading plugin "networkfs"... Mar 25 17:42:46 volumiokueche volumio[29084]: info: Starting Udev Watcher for removable devices Mar 25 17:42:46 volumiokueche volumio[29084]: info: Ignoring mount for partition: boot Mar 25 17:42:46 volumiokueche volumio[29084]: info: Ignoring mount for partition: volumio Mar 25 17:42:46 volumiokueche volumio[29084]: info: Ignoring mount for partition: volumio_data Mar 25 17:42:46 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:42:46 volumiokueche volumio[29084]: info: Loading plugin "volumio_command_line_client"... Mar 25 17:42:46 volumiokueche volumio[29084]: info: Plugin upnp is not enabled Mar 25 17:42:46 volumiokueche volumio[29084]: info: Loading plugin "my_music"... Mar 25 17:42:46 volumiokueche volumio[29084]: info: Loading plugin "mpd"... Mar 25 17:42:46 volumiokueche volumio[29084]: info: Loading plugin "upnp_browser"... Mar 25 17:42:46 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 316. Mar 25 17:42:46 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:46 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:46 volumiokueche go-librespot[29145]: go-librespot daemon starting... Mar 25 17:42:46 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:46 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:46+01:00" level=debug msg="app state loaded" Mar 25 17:42:46 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:47 volumiokueche volumio[29084]: info: Starting UPNP Browser Mar 25 17:42:47 volumiokueche volumio[29084]: info: Loading plugin "alarm-clock"... Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=info msg="zeroconf server listening on port 46363" Mar 25 17:42:47 volumiokueche volumio[29084]: info: Loading plugin "airplay_emulation"... Mar 25 17:42:47 volumiokueche volumio[29084]: info: Starting Shairport Sync Mar 25 17:42:47 volumiokueche volumio[29084]: info: Loading plugin "last_100"... Mar 25 17:42:47 volumiokueche volumio[29084]: info: Loading plugin "webradio"... Mar 25 17:42:47 volumiokueche volumio[29084]: info: Loading plugin "i2s_dacs"... Mar 25 17:42:47 volumiokueche volumio[29084]: info: I2S DAC not set, start Auto-detection Mar 25 17:42:47 volumiokueche volumio[29084]: info: Loading plugin "volumiodiscovery"... Mar 25 17:42:47 volumiokueche volumio[29084]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:47 volumiokueche volumio[29084]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:47 volumiokueche volumio[29084]: *** WARNING *** For more information see Mar 25 17:42:47 volumiokueche volumio[29084]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:47 volumiokueche volumio[29084]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:47 volumiokueche volumio[29084]: *** WARNING *** For more information see Mar 25 17:42:47 volumiokueche node[29084]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:47 volumiokueche node[29084]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:47 volumiokueche node[29084]: *** WARNING *** For more information see Mar 25 17:42:47 volumiokueche node[29084]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:42:47 volumiokueche node[29084]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:42:47 volumiokueche node[29084]: *** WARNING *** For more information see Mar 25 17:42:47 volumiokueche volumio[29084]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 17:42:47 volumiokueche volumio[29084]: info: Discovery: Started advertising with name: VolumioKueche Mar 25 17:42:47 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:42:47 volumiokueche volumio[29084]: info: Loading plugin "spop"... Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=debug msg="obtained new client token: AADAuHoapAYba++E2tOZPkE8y/qLwbi3Q1U65X1I5hx2aC9BB3MF+JdzJeDRnStDKBWWg76M13/MMOMhMER2COgGv9N7j/Nmu5TFfhpgmYRXmVpE1DufmzyU6qGWxZiYH4M8BLCL+tcvA2hpn4+A03+cXmZKAt0PmXbhtbKp6qm7jcBXYoRnIH4X7B728m0kN4EORKcBCTZBJBFLgbBtBK86yvlEX79x/KvLkHsDSSIDbi5uVJsfVNY=" Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=debug msg="completed challenge" Mar 25 17:42:47 volumiokueche go-librespot[29146]: time="2026-03-25T17:42:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:47 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:47 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "now_playing"... Mar 25 17:42:48 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:48] [connect] Successful connection Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "outputs"... Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "albumart"... Mar 25 17:42:48 volumiokueche volumio[29084]: info: Plugin example_plugin is not enabled Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "inputs"... Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "updater_comm"... Mar 25 17:42:48 volumiokueche volumio[29084]: info: Plugin mpdemulation is not enabled Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "rest_api"... Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "websocket"... Mar 25 17:42:48 volumiokueche volumio[29084]: info: Starting Socket.io Server version 1.7.4 Mar 25 17:42:48 volumiokueche volumio[29084]: info: Loading plugin "touch_display"... Mar 25 17:42:48 volumiokueche volumio[29084]: info: Applying required configuration parameters for plugin touch_display Mar 25 17:42:49 volumiokueche volumio[29084]: info: Loading i18n strings for locale en Mar 25 17:42:49 volumiokueche volumio[29084]: Updating browse sources language Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:49 volumiokueche volumio[29155]: Forking 3 albumart workers Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::initPlayerControls Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:42:49 volumiokueche volumio[29084]: Express server listening on port 3000 Mar 25 17:42:49 volumiokueche volumio[29084]: [Metrics] WebUI: 4s 674.64ms Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::resetVolumioState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::getcurrentVolume Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:49 volumiokueche sudo[29122]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:49 volumiokueche volumio[29084]: info: Volumio Network Manager: Network status updated: 2 Mar 25 17:42:49 volumiokueche volumio[29084]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Mar 25 17:42:49 volumiokueche volumio-remote-updater[752]: [2026-03-25 17:42:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774456968 101 Mar 25 17:42:49 volumiokueche volumio[29084]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Mar 25 17:42:49 volumiokueche volumio[29084]: info: VolumeController:: Volume=86 Mute =false Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::pushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::updateTrackBlock Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getTrackBlock Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:42:49 volumiokueche volumio[29084]: info: Reloading queue from file Mar 25 17:42:49 volumiokueche volumio[29084]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Mar 25 17:42:49 volumiokueche volumio[29084]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Mar 25 17:42:49 volumiokueche volumio[29084]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::setRepeat false single undefined Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::pushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::setRandom true Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::pushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: Setting Device type: Raspberry PI Mar 25 17:42:49 volumiokueche volumio[29084]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 25 17:42:49 volumiokueche volumio[29084]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Mar 25 17:42:49 volumiokueche volumio[29084]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 25 17:42:49 volumiokueche volumio[29084]: info: Listing playlists Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetQueue Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::getQueue Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getQueue Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetVisibleSources Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:49 volumiokueche volumio[29084]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Mar 25 17:42:49 volumiokueche volumio[29084]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Mar 25 17:42:49 volumiokueche volumio[29084]: info: Listing playlists Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetQueue Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::getQueue Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getQueue Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetVisibleSources Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:49 volumiokueche volumio[29084]: info: VolumeController:: Volume=86 Mute =false Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreStateMachine::pushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:49 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioPushState Mar 25 17:42:49 volumiokueche volumio[29084]: info: Discovery: adding 3d3a2849-45d3-428b-bde8-ecc2db686765 Mar 25 17:42:49 volumiokueche volumio[29084]: info: Discovery: Found device VolumioBox Mar 25 17:42:49 volumiokueche volumio[29084]: info: Discovery: Connecting to remote: 192.168.2.168 Mar 25 17:42:50 volumiokueche volumio[29084]: info: Discovery: adding 0c0628ca-b4ec-475c-b4de-13a5df363f06 Mar 25 17:42:50 volumiokueche volumio[29084]: info: Discovery: Found device VolumioKueche Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:50 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:50 volumiokueche volumio[29084]: info: Completed loading Core Plugins Mar 25 17:42:50 volumiokueche volumio[29084]: info: Preparing to generate the ALSA configuration file Mar 25 17:42:50 volumiokueche volumio[29084]: info: Discovery: this is already registered, 0c0628ca-b4ec-475c-b4de-13a5df363f06 Mar 25 17:42:50 volumiokueche volumio[29084]: info: Discovery: Found device VolumioKueche Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:50 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:50 volumiokueche volumio[29084]: info: Discovery: Connected to remote: 192.168.2.168 Mar 25 17:42:50 volumiokueche volumio[29084]: info: Asound.conf file written Mar 25 17:42:50 volumiokueche volumio[29166]: Starting albumart workers Mar 25 17:42:50 volumiokueche volumio[29167]: Starting albumart workers Mar 25 17:42:50 volumiokueche sudo[29215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 25 17:42:50 volumiokueche sudo[29215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:50 volumiokueche sudo[29215]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:50 volumiokueche volumio[29084]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 25 17:42:50 volumiokueche volumio[29084]: info: Output device has changed, restarting MPD Mar 25 17:42:50 volumiokueche volumio[29168]: Starting albumart workers Mar 25 17:42:50 volumiokueche volumio[29084]: info: Output device has changed, restarting Shairport Sync Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:50 volumiokueche sudo[29221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:42:50 volumiokueche sudo[29221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:50 volumiokueche volumio[29084]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:50 volumiokueche sudo[29221]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:50 volumiokueche volumio[29084]: info: ___________ START PLUGINS ___________ Mar 25 17:42:50 volumiokueche sudo[29223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:42:50 volumiokueche sudo[29223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:50 volumiokueche volumio[29084]: info: ControllerMpd::onStart: Initializing MPD Mar 25 17:42:50 volumiokueche volumio[29084]: info: Creating MPD Configuration file Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:50 volumiokueche volumio[29084]: info: [1774456970587] CoreMusicLibrary::Adding element Media Servers Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:50 volumiokueche sudo[29233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:42:50 volumiokueche sudo[29233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:50 volumiokueche volumio[29084]: info: UPNP Browser: Client initialized successfully Mar 25 17:42:50 volumiokueche systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 17:42:50 volumiokueche sudo[29231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:42:50 volumiokueche sudo[29231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:50 volumiokueche sudo[29231]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:50 volumiokueche systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:42:50 volumiokueche systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:42:50 volumiokueche systemd[1]: mpd.service: Consumed 1.486s CPU time. Mar 25 17:42:50 volumiokueche systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:42:50 volumiokueche systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:42:50 volumiokueche systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:42:50 volumiokueche volumio[29084]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:50 volumiokueche volumio[29084]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:50 volumiokueche volumio[29084]: info: [1774456970797] CoreMusicLibrary::Adding element Last_100 Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:50 volumiokueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:50 volumiokueche volumio[29084]: info: [1774456970803] CoreMusicLibrary::Adding element Webradio Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:50 volumiokueche systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:42:50 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:50 volumiokueche volumio[29084]: info: Initializing BBC Radios Mar 25 17:42:50 volumiokueche sudo[29245]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 17:42:50 volumiokueche sudo[29245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 17:42:50 volumiokueche sudo[29245]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:51 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:51 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:51 volumiokueche volumio[29084]: info: Creating Spotify config file Mar 25 17:42:51 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:51 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 317. Mar 25 17:42:51 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:51 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:51 volumiokueche go-librespot[29261]: go-librespot daemon starting... Mar 25 17:42:51 volumiokueche go-librespot[29262]: time="2026-03-25T17:42:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:51 volumiokueche go-librespot[29262]: time="2026-03-25T17:42:51+01:00" level=info msg="zeroconf server listening on port 41419" Mar 25 17:42:51 volumiokueche volumio[29084]: info: [now-playing] ConfigUpdater: config is up to date. Mar 25 17:42:51 volumiokueche volumio[29084]: info: Loading i18n strings for locale en Mar 25 17:42:51 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:42:51 volumiokueche volumio[29084]: info: Volumio Calling Home Mar 25 17:42:51 volumiokueche sudo[29285]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Mar 25 17:42:51 volumiokueche sudo[29285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:51 volumiokueche sudo[29285]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:51 volumiokueche sudo[29299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 25 17:42:51 volumiokueche sudo[29297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 25 17:42:51 volumiokueche sudo[29297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:51 volumiokueche sudo[29299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:51 volumiokueche sudo[29300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 25 17:42:51 volumiokueche sudo[29300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche systemd[1]: Reloading. Mar 25 17:42:52 volumiokueche volumio[29084]: info: [now-playing] Fetching API key... Mar 25 17:42:52 volumiokueche volumio[29084]: info: [now-playing] App is listening on port 4004. Mar 25 17:42:52 volumiokueche volumio[29084]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Mar 25 17:42:52 volumiokueche volumio[29084]: info: touch_display: Backlight interface detected. Mar 25 17:42:52 volumiokueche volumio[29084]: info: MPD Permissions set Mar 25 17:42:52 volumiokueche volumio[29084]: info: MPD Permissions set Mar 25 17:42:52 volumiokueche sudo[29324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Mar 25 17:42:52 volumiokueche sudo[29324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche volumio[29084]: info: Volumio called home Mar 25 17:42:52 volumiokueche sudo[29324]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:52 volumiokueche volumio[29084]: info: Spotify config file written Mar 25 17:42:52 volumiokueche sudo[29327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 17:42:52 volumiokueche volumio[29084]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 25 17:42:52 volumiokueche sudo[29327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:42:52 volumiokueche volumio[29084]: info: No need to fix Spotify hosts Mar 25 17:42:52 volumiokueche volumio[29084]: info: touch_display: IframeKeyboardBridge extension installed successfully Mar 25 17:42:52 volumiokueche volumio[29084]: info: touch_display: Raspberry Pi Foundation touch screen detected. Mar 25 17:42:52 volumiokueche sudo[29342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Mar 25 17:42:52 volumiokueche sudo[29342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche sudo[29343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 25 17:42:52 volumiokueche sudo[29342]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:52 volumiokueche sudo[29343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche sudo[29343]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:52 volumiokueche sudo[29347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Mar 25 17:42:52 volumiokueche sudo[29347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche sudo[29347]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:52 volumiokueche volumio[29084]: info: Starting Shairport Sync Mar 25 17:42:52 volumiokueche volumio[29084]: info: Starting Shairport Sync Mar 25 17:42:52 volumiokueche volumio[29084]: info: Starting Shairport Sync Mar 25 17:42:52 volumiokueche sudo[29350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:52 volumiokueche sudo[29350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche volumio[29084]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 25 17:42:52 volumiokueche volumio[29084]: SPOTIFY: BQC3zMUJBezSLJ2z15v4i_HD3LTJHKzYKVU1SECvqIUtR_9RZG0nKW7y0xMv25suzLYR8T965o25VKnyblYsQs8pTEurlGtf3bNXE7nVJZR-phGeDs4I5CizwtoZsQw8xJDSaitectdjbJB25wjIT5k5A25qyaieCpt64fo5xI9AOxJO7enXzaxYjac5usDHZyVh1oL_mw9y7sPsMjU2KTm30Gj6-R5o15zMQJklIu8u7VET65fC45SaxXm4d9UwlAdYxwYqbc9I8cec_LT3N0FYg7FL4JMw Mar 25 17:42:52 volumiokueche volumio[29084]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 25 17:42:52 volumiokueche volumio[29084]: info: New Spotify access token = BQC3zMUJBezSLJ2z15v4i_HD3LTJHKzYKVU1SECvqIUtR_9RZG0nKW7y0xMv25suzLYR8T965o25VKnyblYsQs8pTEurlGtf3bNXE7nVJZR-phGeDs4I5CizwtoZsQw8xJDSaitectdjbJB25wjIT5k5A25qyaieCpt64fo5xI9AOxJO7enXzaxYjac5usDHZyVh1oL_mw9y7sPsMjU2KTm30Gj6-R5o15zMQJklIu8u7VET65fC45SaxXm4d9UwlAdYxwYqbc9I8cec_LT3N0FYg7FL4JMw Mar 25 17:42:52 volumiokueche volumio[29084]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 25 17:42:52 volumiokueche sudo[29354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:52 volumiokueche sudo[29354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche sudo[29352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:42:52 volumiokueche sudo[29352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:52 volumiokueche volumio[29084]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Mar 25 17:42:52 volumiokueche volumio[29084]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 25 17:42:52 volumiokueche volumio[29084]: info: touch_display: File permissions for backlight brightness control set. Mar 25 17:42:52 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:52 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:53 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:53 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:53 volumiokueche sudo[29300]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:53 volumiokueche systemd[1]: Reloading. Mar 25 17:42:53 volumiokueche mpd[29260]: 2026-03-25T17:42:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:42:53 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:53 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:53 volumiokueche volumio[29084]: info: touch_display: systemctl daemon-reload succeeded. Mar 25 17:42:53 volumiokueche sudo[29364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 25 17:42:53 volumiokueche sudo[29364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:53 volumiokueche volumio[29084]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): Could not obtain API key Mar 25 17:42:53 volumiokueche volumio[29084]: SPOTIFY: User informations: {"country":"DE","display_name":"oradke","email":"oradke@outlook.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/oradke"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/oradke","id":"oradke","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee857bfaea58dba3bad8441935b4","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b827bfaea58dba3bad8441935b4","width":64}],"product":"premium","type":"user","uri":"spotify:user:oradke"} Mar 25 17:42:53 volumiokueche volumio[29084]: info: Spotify Successfully logged in Mar 25 17:42:53 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:42:53 volumiokueche volumio[29084]: info: [1774456973454] CoreMusicLibrary::Adding element Spotify Mar 25 17:42:53 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:42:53 volumiokueche volumio[29084]: Cannot find translation for source Spotify Mar 25 17:42:53 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:53 volumiokueche systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:54 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:54 volumiokueche systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:42:54 volumiokueche systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:42:54 volumiokueche sudo[29233]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche sudo[29223]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche sudo[29299]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 25 17:42:54 volumiokueche volumio[29084]: error: MPD error: The expression evaluated to a falsy value: Mar 25 17:42:54 volumiokueche volumio[29084]: assert.ok(self.idling) Mar 25 17:42:54 volumiokueche volumio[29084]: error: The expression evaluated to a falsy value: Mar 25 17:42:54 volumiokueche volumio[29084]: assert.ok(self.idling) Mar 25 17:42:54 volumiokueche volumio[29084]: error: updateQueue error: null Mar 25 17:42:54 volumiokueche systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 17:42:54 volumiokueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:42:54 volumiokueche sudo[29364]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche volumio[29084]: info: MPD running with PID29260 Mar 25 17:42:54 volumiokueche volumio[29084]: ,establishing connection Mar 25 17:42:54 volumiokueche volumio[29084]: error: updateQueue error: null Mar 25 17:42:54 volumiokueche systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:42:54 volumiokueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:54 volumiokueche systemd[1]: shairport-sync.service: Consumed 1.684s CPU time. Mar 25 17:42:54 volumiokueche systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 17:42:54 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: Volumio Kiosk started. Mar 25 17:42:54 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:54 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:54 volumiokueche sudo[29297]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche volumio[29084]: info: Completed starting Core Plugins Mar 25 17:42:54 volumiokueche volumio[29084]: info: ------------------------------------------- Mar 25 17:42:54 volumiokueche volumio[29084]: info: ----- MyVolumio plugins startup ---- Mar 25 17:42:54 volumiokueche volumio[29084]: info: ------------------------------------------- Mar 25 17:42:54 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 17:42:54 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:54 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 25 17:42:54 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:54 volumiokueche go-librespot[29387]: go-librespot daemon starting... Mar 25 17:42:54 volumiokueche sudo[29327]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:42:54 volumiokueche sudo[29354]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche sudo[29350]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:54 volumiokueche volumio[29084]: info: Shairport-Sync Started Mar 25 17:42:54 volumiokueche volumio[29084]: Error adding Membership: Error: addMembership EINVAL Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=debug msg="app state loaded" Mar 25 17:42:54 volumiokueche sudo[29352]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:54 volumiokueche volumio[29084]: info: Shairport-Sync Started Mar 25 17:42:54 volumiokueche volumio[29084]: info: Shairport-Sync Started Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: X display number found: 0 Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: X display number found: 0 Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 25 17:42:54 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:42:54 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: X display number found: 0 Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=info msg="zeroconf server listening on port 39163" Mar 25 17:42:54 volumiokueche volumio[29084]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=debug msg="obtained new client token: AAD7IW7SdGsbEmS0YqOM1oTtZ/+hZFd2S5LxCItpCobHLDnddHai147k/rdKAXD83u3/kKMARCW2UNJCboAerU7n3d1qo5vtemz+5Awh0QEWBm5jRKPKHbL+ASuExixC98LMHWyO5CNKXtHRqfTUYXxukIuWuqnwWkcOmyF9wHP0wihSwMRoxFHJ05B4ItlnU5UB5D4A3nSlinulQBlJAKYZud6zQP8qbwURuj/CFJtZzm8uelGQUjw=" Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:54 volumiokueche go-librespot[29388]: time="2026-03-25T17:42:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:42:54 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:54 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:57 volumiokueche sudo[29435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:42:57 volumiokueche sudo[29435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:57 volumiokueche sudo[29437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:42:57 volumiokueche sudo[29437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:42:57 volumiokueche systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 17:42:57 volumiokueche systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 17:42:57 volumiokueche systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:57 volumiokueche systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 17:42:57 volumiokueche sudo[29435]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:57 volumiokueche mpd_monitor.sh[29440]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 17:42:57 volumiokueche systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 108. Mar 25 17:42:57 volumiokueche sudo[29437]: pam_unix(sudo:session): session closed for user root Mar 25 17:42:57 volumiokueche volumio[29084]: info: Successfully started MPD Monitor Mar 25 17:42:57 volumiokueche volumio[29084]: info: Successfully started MPD Monitor Mar 25 17:42:57 volumiokueche systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:57 volumiokueche systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 25 17:42:57 volumiokueche upmpdcli[29443]: Could not open config: /tmp/upmpdcli.conf Mar 25 17:42:57 volumiokueche systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:57 volumiokueche systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 25 17:42:57 volumiokueche volumio[29084]: info: go-librespot daemon successfully initialized Mar 25 17:42:57 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 17:42:57 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:57 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:42:57 volumiokueche go-librespot[29445]: go-librespot daemon starting... Mar 25 17:42:57 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:57+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:42:57 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:57+01:00" level=debug msg="app state loaded" Mar 25 17:42:57 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=info msg="zeroconf server listening on port 35691" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=debug msg="obtained new client token: AADisofQgo04gzqdEBJMKovoUuxOBKzSiWzLWbw7+OhmgvUb0oo66FONPAoPDuNiBF5urufI0QByEcMmiafpplDm7b5jYlYE7oJwVRjctPifqKMjoxpBZgQpxQiVrg4hYYlVibseWwloa6LcMMDF2o95RbcWNL8hJAGr1lXtZB6bKaHSmrp8xESEbwlLSl6eUpYLOz38sok12LGJc6EbbvQm1nHyk8p+NvRboSGlVAaZkmkc55DM6Yw=" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=debug msg="completed keyexchange" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=debug msg="completed challenge" Mar 25 17:42:58 volumiokueche go-librespot[29446]: time="2026-03-25T17:42:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:42:58 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:42:58 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:42:59 volumiokueche volumio[29084]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 17:43:00 volumiokueche volumio[29084]: info: Initializing connection to go-librespot Websocket Mar 25 17:43:00 volumiokueche volumio[29084]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:43:01 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 17:43:01 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:43:01 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:43:01 volumiokueche go-librespot[29453]: go-librespot daemon starting... Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=debug msg="app state loaded" Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=info msg="zeroconf server listening on port 41439" Mar 25 17:43:01 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:01+01:00" level=debug msg="obtained new client token: AADGAdjB319LMBazOM8yVi7T/RggOwQscdun1gl3Wn/qBsST4V9Bp+iOcRjIRjTPvNRG9vkMyPK9s+6b2SnkI0MRhVelkgmGp68zsSZ25KqnzdlhECt5RLIKypsSNxeOmzBq5PnDN4X/9o40giPjmsVzoOY5BDjrfI5SUrxWqYX8ppXLKDjDibqfkRAFwGZzmdXack5b3hN7vDBoXAgx6fDTcL27UHv1dhbNwFwpwH+fepWqmGx+FBQ=" Mar 25 17:43:02 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:43:02 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:02+01:00" level=debug msg="completed keyexchange" Mar 25 17:43:02 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:02+01:00" level=debug msg="completed challenge" Mar 25 17:43:02 volumiokueche go-librespot[29454]: time="2026-03-25T17:43:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:43:02 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:43:02 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 17:43:02 volumiokueche volumio[29084]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 17:43:02 volumiokueche volumio[29084]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 17:43:02 volumiokueche volumio[29084]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 17:43:02 volumiokueche volumio[29084]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 17:43:02 volumiokueche volumio[29084]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 17:43:02 volumiokueche volumio[29084]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 17:43:02 volumiokueche volumio[29084]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 17:43:02 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 17:43:03 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 17:43:03 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 17:43:03 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:43:03 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:43:03 volumiokueche volumio[29084]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 17:43:03 volumiokueche volumio[29084]: info: MyVolumio login type: Token Mar 25 17:43:03 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 17:43:03 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 17:43:03 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 17:43:03 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 17:43:03 volumiokueche volumio[29084]: info: Streaming services startup Mar 25 17:43:03 volumiokueche volumio[29084]: info: Starting Streaming Daemon Mar 25 17:43:03 volumiokueche sudo[29462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:43:03 volumiokueche sudo[29462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:03 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 17:43:03 volumiokueche sudo[29462]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:03 volumiokueche volumio[29084]: info: Initializing connection to go-librespot Websocket Mar 25 17:43:03 volumiokueche volumio[29084]: error: Cannot start Volumio Streaming Daemon Mar 25 17:43:03 volumiokueche volumio[29084]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:43:03 volumiokueche volumio[29084]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:43:03 volumiokueche volumio[29084]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:43:04 volumiokueche volumio[29084]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 17:43:05 volumiokueche volumio[29084]: info: MyVolumio token set successfully Mar 25 17:43:05 volumiokueche volumio[29084]: info: MYVOLUMIO: Adding device Mar 25 17:43:05 volumiokueche volumio[29084]: info: MYVOLUMIO: Evaluating Server Mar 25 17:43:05 volumiokueche systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 17:43:05 volumiokueche systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:43:05 volumiokueche systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:43:05 volumiokueche go-librespot[29470]: go-librespot daemon starting... Mar 25 17:43:05 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:43:05 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:05+01:00" level=debug msg="app state loaded" Mar 25 17:43:05 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:43:05 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:43:05 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:43:05 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:43:05 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:05+01:00" level=info msg="zeroconf server listening on port 33947" Mar 25 17:43:05 volumiokueche volumio[29084]: info: MyVolumio Plan changed: premium Mar 25 17:43:05 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 25 17:43:05 volumiokueche volumio[29084]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 17:43:05 volumiokueche volumio[29084]: info: Removing audio output: Mar 25 17:43:05 volumiokueche volumio[29084]: info: MYVOLUMIO: Adding device Mar 25 17:43:05 volumiokueche volumio[29084]: info: MYVOLUMIO: Evaluating Server Mar 25 17:43:05 volumiokueche volumio[29084]: info: Remote config written successfully Mar 25 17:43:05 volumiokueche volumio[29084]: info: Starting Tunnel 1 Mar 25 17:43:05 volumiokueche volumio[29084]: info: Starting Tunnel Connection Checker Mar 25 17:43:05 volumiokueche volumio[29084]: info: Completed starting MyVolumio Plugin Mar 25 17:43:05 volumiokueche volumio[29084]: info: MYVolumio Device enabled Mar 25 17:43:05 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 25 17:43:05 volumiokueche volumio[29084]: info: MyVolumio status changed Mar 25 17:43:05 volumiokueche volumio[29084]: info: Streaming services startup Mar 25 17:43:05 volumiokueche volumio[29084]: info: Starting Streaming Daemon Mar 25 17:43:05 volumiokueche sudo[29516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:43:05 volumiokueche sudo[29516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:05 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 25 17:43:05 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 25 17:43:05 volumiokueche sudo[29516]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:05 volumiokueche volumio[29084]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 25 17:43:05 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 25 17:43:06 volumiokueche sudo[29534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 25 17:43:06 volumiokueche sudo[29534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche sudo[29534]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:06 volumiokueche volumio[29084]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: MultiRoom plugin initialized Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: STOPPING SNAPCLIENT Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: Snap server stop Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: STOPPING volumioStreaming Mar 25 17:43:06 volumiokueche sudo[29551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 25 17:43:06 volumiokueche sudo[29551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche sudo[29553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 25 17:43:06 volumiokueche sudo[29553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 25 17:43:06 volumiokueche sudo[29556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 25 17:43:06 volumiokueche sudo[29556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche sudo[29559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 25 17:43:06 volumiokueche sudo[29559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 25 17:43:06 volumiokueche sudo[29559]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 25 17:43:06 volumiokueche sudo[29551]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:06 volumiokueche sudo[29553]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 25 17:43:06 volumiokueche sudo[29556]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 25 17:43:06 volumiokueche volumio[29084]: info: Preparing to generate the ALSA configuration file Mar 25 17:43:06 volumiokueche volumio[29084]: info: Initializing connection to go-librespot Websocket Mar 25 17:43:06 volumiokueche volumio[29084]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 25 17:43:06 volumiokueche volumio[29084]: info: Reading ALSA contributions from plugins. Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: Removed streaming files Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: volumioStreaming STOPPED Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: SNAPSERVER STOPPED Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: SNAPCLIENT STOPPED Mar 25 17:43:06 volumiokueche volumio[29084]: error: Cannot start Volumio Streaming Daemon Mar 25 17:43:06 volumiokueche volumio[29084]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:43:06 volumiokueche volumio[29084]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:43:06 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:06+01:00" level=debug msg="new websocket client" Mar 25 17:43:06 volumiokueche volumio[29084]: info: Connection to go-librespot Websocket established Mar 25 17:43:06 volumiokueche volumio[29084]: info: Asound.conf file written Mar 25 17:43:06 volumiokueche sudo[29564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 25 17:43:06 volumiokueche sudo[29564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche sudo[29564]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:06 volumiokueche volumio[29084]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 25 17:43:06 volumiokueche volumio[29084]: info: Output device has changed, restarting MPD Mar 25 17:43:06 volumiokueche volumio[29084]: info: Output device has changed, restarting Shairport Sync Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:43:06 volumiokueche sudo[29570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:43:06 volumiokueche sudo[29570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche sudo[29570]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:06 volumiokueche sudo[29572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:43:06 volumiokueche volumio[29084]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:43:06 volumiokueche sudo[29572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: Pushing multiroomSync output for this device Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: Pushing multiroomSync output Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding audio output: Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding audio output: Mar 25 17:43:06 volumiokueche systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 17:43:06 volumiokueche volumio[29084]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding METAVOLUMIO REST API Endpoints Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Plugin smart_inputs disabled by user. Not starting Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 25 17:43:06 volumiokueche volumio[29084]: error: Hi Res Audio Failed Login: Missing Login Data Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 25 17:43:06 volumiokueche systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 25 17:43:06 volumiokueche systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:43:06 volumiokueche systemd[1]: mpd.service: Consumed 2.117s CPU time. Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 25 17:43:06 volumiokueche systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Mar 25 17:43:06 volumiokueche volumio[29084]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Mar 25 17:43:06 volumiokueche systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:43:06 volumiokueche systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding TIDAL REST API Endpoints Mar 25 17:43:06 volumiokueche volumio[29084]: info: Stopping AccessToken refresher cron for QOBUZ Mar 25 17:43:06 volumiokueche volumio[29084]: info: AccessToken refresher cron started for QOBUZ Mar 25 17:43:06 volumiokueche volumio[29084]: info: Adding QOBUZ REST API Endpoints Mar 25 17:43:06 volumiokueche systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:43:06 volumiokueche volumio[29084]: info: MPD Permissions set Mar 25 17:43:06 volumiokueche systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:06 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:07 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:43:07 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:07 volumiokueche volumio[29084]: [Metrics] CommandRouter: 22s 207.68ms Mar 25 17:43:07 volumiokueche volumio[29084]: info: CoreCommandRouter::volumiosetStartupVolume Mar 25 17:43:07 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:43:07 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:43:07 volumiokueche volumio[29084]: info: CoreCommandRouter::Close All Modals sent Mar 25 17:43:07 volumiokueche volumio[29084]: info: CoreCommandRouter::Close All Modals sent Mar 25 17:43:07 volumiokueche volumio[29084]: info: Starting Shairport Sync Mar 25 17:43:07 volumiokueche sudo[29594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:43:07 volumiokueche sudo[29594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:07 volumiokueche systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:43:07 volumiokueche systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:43:07 volumiokueche systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:43:07 volumiokueche systemd[1]: shairport-sync.service: Consumed 1.593s CPU time. Mar 25 17:43:07 volumiokueche sudo[29585]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 17:43:07 volumiokueche sudo[29585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 17:43:07 volumiokueche sudo[29585]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:07 volumiokueche systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:43:07 volumiokueche sudo[29594]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:07 volumiokueche volumio[29084]: info: Shairport-Sync Started Mar 25 17:43:08 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 25 17:43:08 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 25 17:43:08 volumiokueche volumio[29084]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 25 17:43:08 volumiokueche mpd[29598]: 2026-03-25T17:43:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:43:08 volumiokueche systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:43:08 volumiokueche sudo[29572]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:08 volumiokueche volumio[29084]: error: updateQueue error: null Mar 25 17:43:09 volumiokueche volumio[29084]: info: Getting Spotify volume Mar 25 17:43:09 volumiokueche volumio[29084]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 25 17:43:09 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:43:09 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:43:09 volumiokueche volumio[29084]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 25 17:43:09 volumiokueche volumio[29084]: SPOTIFY: SPOTIFY VOLUME undefined Mar 25 17:43:09 volumiokueche volumio[29084]: SPOTIFY: VOLUMIO VOLUME 86 Mar 25 17:43:09 volumiokueche volumio[29084]: info: Aligning Spotify Volume to Volumio Volume Mar 25 17:43:09 volumiokueche volumio[29084]: info: CoreCommandRouter::volumioGetState Mar 25 17:43:09 volumiokueche volumio[29084]: info: CorePlayQueue::getTrack 0 Mar 25 17:43:09 volumiokueche volumio[29084]: info: Setting Spotify Volume from Volumio: 86 Mar 25 17:43:10 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:10+01:00" level=debug msg="obtained new client token: AAAlnlWB0v5uwQBbJOSuK46qUdExy5jvlW6T/jDK7oVrjaaFeled1pW2x9NPCJGYde4GsqFE84PB+ZDvW/2QxtjvIJ9VxZ5xPZi2ZhJAKneQsAgquy+eziQnIguL6rXUF21O5Ha83YiLKJgu5ZyzGxICoBAEiwKhwiCWlaqmkyT/mRWAOwyBagpfAhIAJZGq1OF+pdh7O0IjrMw8vIK6xY5AkrzA7tDNICmANOFd3k968QmMb5kc1zg=" Mar 25 17:43:10 volumiokueche sudo[29625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 25 17:43:10 volumiokueche sudo[29625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:43:10 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:43:10 volumiokueche autossh[28435]: received signal to exit (15) Mar 25 17:43:10 volumiokueche systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Mar 25 17:43:10 volumiokueche systemd[1]: sshtunnel.service: Deactivated successfully. Mar 25 17:43:10 volumiokueche systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Mar 25 17:43:10 volumiokueche go-librespot[29471]: time="2026-03-25T17:43:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.188.182:35562->34.158.1.133:4070: read: connection reset by peer" Mar 25 17:43:10 volumiokueche volumio[29084]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:43:10 volumiokueche volumio[29084]: Error: socket hang up Mar 25 17:43:10 volumiokueche volumio[29084]: at connResetException (node:internal/errors:720:14) Mar 25 17:43:10 volumiokueche volumio[29084]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 17:43:10 volumiokueche volumio[29084]: at Socket.emit (node:events:526:35) Mar 25 17:43:10 volumiokueche volumio[29084]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 17:43:10 volumiokueche volumio[29084]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 17:43:10 volumiokueche volumio[29084]: code: 'ECONNRESET', Mar 25 17:43:10 volumiokueche volumio[29084]: response: undefined Mar 25 17:43:10 volumiokueche volumio[29084]: } Mar 25 17:43:10 volumiokueche volumio[29084]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:43:10 volumiokueche systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Mar 25 17:43:10 volumiokueche systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:43:10 volumiokueche systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:43:10 volumiokueche sudo[29625]: pam_unix(sudo:session): session closed for user root Mar 25 17:43:10 volumiokueche autossh[29639]: port set to 0, monitoring disabled Mar 25 17:43:10 volumiokueche autossh[29639]: starting ssh (count 1) Mar 25 17:43:10 volumiokueche autossh[29639]: ssh child pid is 29642 Mar 25 17:43:10 volumiokueche volumiossh-tunnel[29642]: Warning: Permanently added '[eu1.myvolumio.org]:2222' (RSA) to the list of known hosts. Mar 25 17:43:10 volumiokueche sudo[29646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 17:42' Mar 25 17:43:10 volumiokueche sudo[29646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"