May 30 15:39:00 terrasse volumio5-onboarding[1207]: time=2026-05-30T15:39:00.352+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:55192->127.0.0.1:3000: i/o timeout" May 30 15:39:00 terrasse volumio[30883]: info: Loading plugin "squeezelite_mc"... May 30 15:39:01 terrasse go-librespot[30899]: time="2026-05-30T15:39:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 30 15:39:01 terrasse systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 30 15:39:01 terrasse systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 30 15:39:01 terrasse volumio[30883]: info: Loading plugin "outputs"... May 30 15:39:01 terrasse volumio[30883]: info: Loading plugin "albumart"... May 30 15:39:01 terrasse volumio[30883]: info: Plugin example_plugin is not enabled May 30 15:39:01 terrasse volumio[30883]: info: Loading plugin "inputs"... May 30 15:39:02 terrasse volumio[30883]: info: Loading plugin "updater_comm"... May 30 15:39:02 terrasse volumio[30883]: info: Plugin mpdemulation is not enabled May 30 15:39:02 terrasse volumio[30883]: info: Loading plugin "rest_api"... May 30 15:39:02 terrasse volumio[30883]: info: Loading plugin "websocket"... May 30 15:39:02 terrasse volumio[30883]: info: Starting Socket.io Server version 1.7.4 May 30 15:39:02 terrasse volumio[30883]: info: Loading i18n strings for locale de May 30 15:39:02 terrasse volumio[30883]: Updating browse sources language May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::initPlayerControls May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 15:39:02 terrasse volumio[30883]: Express server listening on port 3000 May 30 15:39:02 terrasse volumio[30883]: [Metrics] WebUI: 12s 383.38ms May 30 15:39:02 terrasse volumio[30883]: info: CoreStateMachine::resetVolumioState May 30 15:39:02 terrasse volumio[30883]: info: CoreStateMachine::getcurrentVolume May 30 15:39:02 terrasse volumio[30883]: info: CoreCommandRouter::volumioRetrievevolume May 30 15:39:02 terrasse volumio[30883]: info: Cannot read play queue from file May 30 15:39:02 terrasse volumio[30883]: info: Volumio Network Manager: Network status updated: 1 May 30 15:39:03 terrasse volumio[30961]: Forking 3 albumart workers May 30 15:39:03 terrasse volumio[30883]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 30 15:39:03 terrasse volumio[30883]: wlan0 Interface doesn't support scanning. May 30 15:39:03 terrasse volumio[30883]: info: Cannot use regular scanning, forcing with ap-force May 30 15:39:03 terrasse sudo[30980]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 30 15:39:03 terrasse sudo[30980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:03 terrasse sudo[30980]: pam_unix(sudo:session): session closed for user root May 30 15:39:03 terrasse volumio[30883]: command failed: No such device (-19) May 30 15:39:03 terrasse volumio[30883]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 30 15:39:03 terrasse volumio[30883]: command failed: No such device (-19) May 30 15:39:03 terrasse volumio[30883]: info: VolumeController:: Volume=0 Mute =true May 30 15:39:03 terrasse volumio[30883]: info: CoreStateMachine::pushState May 30 15:39:03 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:03 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:39:03 terrasse volumio[30883]: info: CoreCommandRouter::volumioPushState May 30 15:39:03 terrasse volumio[30883]: info: CoreStateMachine::updateTrackBlock May 30 15:39:03 terrasse volumio[30883]: info: CorePlayQueue::getTrackBlock May 30 15:39:03 terrasse volumio[30883]: info: CoreCommandRouter::volumioRetrievevolume May 30 15:39:03 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:03 terrasse volumio[30883]: info: Executing start script for DAC IQaudIO DAC Plus May 30 15:39:03 terrasse volumio[30883]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 May 30 15:39:03 terrasse volumio[30883]: info: CoreStateMachine::setRepeat null single undefined May 30 15:39:03 terrasse volumio[30883]: info: CoreStateMachine::pushState May 30 15:39:03 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:03 terrasse volumio[30883]: info: CoreCommandRouter::volumioPushState May 30 15:39:03 terrasse volumio[30883]: info: CoreStateMachine::setRandom null May 30 15:39:03 terrasse volumio[30883]: info: CoreStateMachine::pushState May 30 15:39:03 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:03 terrasse volumio[30883]: info: CoreCommandRouter::volumioPushState May 30 15:39:03 terrasse volumio[30883]: info: Setting Device type: Raspberry PI May 30 15:39:03 terrasse volumio[30883]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 May 30 15:39:03 terrasse volumio[30883]: info: DAC script executed May 30 15:39:03 terrasse volumio[30883]: info: Completed loading Core Plugins May 30 15:39:03 terrasse volumio[30883]: info: Preparing to generate the ALSA configuration file May 30 15:39:04 terrasse volumio[30883]: info: VolumeController:: Volume=0 Mute =true May 30 15:39:04 terrasse volumio[30883]: info: CoreStateMachine::pushState May 30 15:39:04 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::volumioPushState May 30 15:39:04 terrasse volumio[30883]: info: Asound.conf file unchanged, so no further update is needed May 30 15:39:04 terrasse volumio[30883]: info: Output device has changed, restarting MPD May 30 15:39:04 terrasse volumio[30883]: info: ___________ START PLUGINS ___________ May 30 15:39:04 terrasse systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. May 30 15:39:04 terrasse sudo[31028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 15:39:04 terrasse systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 30 15:39:04 terrasse sudo[31028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:04 terrasse sudo[31028]: pam_unix(sudo:session): session closed for user root May 30 15:39:04 terrasse volumio[30883]: info: ControllerMpd::onStart: Initializing MPD May 30 15:39:04 terrasse volumio[30883]: info: Creating MPD Configuration file May 30 15:39:04 terrasse sudo[31030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 15:39:04 terrasse systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 30 15:39:04 terrasse go-librespot[31032]: go-librespot daemon starting... May 30 15:39:04 terrasse sudo[31030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 15:39:04 terrasse volumio[30883]: info: [1780148344448] CoreMusicLibrary::Adding element Last_100 May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:39:04 terrasse sudo[31034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service May 30 15:39:04 terrasse sudo[31034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 15:39:04 terrasse volumio[30883]: info: [1780148344481] CoreMusicLibrary::Adding element Webradio May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:39:04 terrasse go-librespot[31037]: time="2026-05-30T15:39:04+02:00" level=info msg="running go-librespot 0.7.1" May 30 15:39:04 terrasse go-librespot[31037]: time="2026-05-30T15:39:04+02:00" level=debug msg="app state loaded" May 30 15:39:04 terrasse sudo[31036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 15:39:04 terrasse sudo[31036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 15:39:04 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1132. May 30 15:39:04 terrasse sudo[31036]: pam_unix(sudo:session): session closed for user root May 30 15:39:04 terrasse go-librespot[31037]: time="2026-05-30T15:39:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 30 15:39:04 terrasse volumio[30883]: info: Initializing BBC Radios May 30 15:39:04 terrasse systemd[1]: Stopping mpd.service - Music Player Daemon... May 30 15:39:04 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:04 terrasse sudo[31045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 15:39:04 terrasse sudo[31045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:04 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:04 terrasse systemd[1]: mpd.service: Deactivated successfully. May 30 15:39:04 terrasse systemd[1]: Stopped mpd.service - Music Player Daemon. May 30 15:39:04 terrasse systemd[1]: mpd.service: Consumed 6.966s CPU time. May 30 15:39:04 terrasse systemd[1]: mpd.socket: Deactivated successfully. May 30 15:39:04 terrasse systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 30 15:39:04 terrasse sudo[31034]: pam_unix(sudo:session): session closed for user root May 30 15:39:04 terrasse systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 30 15:39:04 terrasse systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 15:39:04 terrasse systemd[1]: Starting mpd.service - Music Player Daemon... May 30 15:39:04 terrasse upmpdcli[31051]: Could not open config: /tmp/upmpdcli.conf May 30 15:39:04 terrasse volumio-remote-updater[594]: [2026-05-30 15:39:04] [connect] Successful connection May 30 15:39:04 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:39:04 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:39:04 terrasse systemd[1]: mpd.service: Deactivated successfully. May 30 15:39:04 terrasse systemd[1]: Stopped mpd.service - Music Player Daemon. May 30 15:39:04 terrasse systemd[1]: mpd.socket: Deactivated successfully. May 30 15:39:04 terrasse systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 30 15:39:04 terrasse systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 15:39:04 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:04 terrasse systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 15:39:05 terrasse volumio[30883]: info: Creating Spotify config file May 30 15:39:05 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:05 terrasse systemd[1]: Starting mpd.service - Music Player Daemon... May 30 15:39:05 terrasse sudo[31070]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 30 15:39:05 terrasse sudo[31070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 15:39:05 terrasse sudo[31070]: pam_unix(sudo:session): session closed for user root May 30 15:39:06 terrasse volumio[30883]: info: [squeezelite_mc] Starting proxy server... May 30 15:39:06 terrasse volumio[30883]: info: Volumio Calling Home May 30 15:39:06 terrasse volumio[30883]: info: [squeezelite_mc] Proxy server started on port 34263 May 30 15:39:06 terrasse volumio[30977]: Starting albumart workers May 30 15:39:06 terrasse volumio[30883]: info: CoreCommandRouter::volumioRetrievevolume May 30 15:39:07 terrasse volumio[30981]: Starting albumart workers May 30 15:39:07 terrasse volumio[30883]: info: MPD Permissions set May 30 15:39:07 terrasse volumio[30883]: info: MPD Permissions set May 30 15:39:07 terrasse volumio-remote-updater[594]: [2026-05-30 15:39:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1780148344 101 May 30 15:39:07 terrasse volumio[30883]: 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 May 30 15:39:07 terrasse volumio[30883]: info: Spotify config file written May 30 15:39:07 terrasse volumio[30883]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 30 15:39:07 terrasse volumio[30883]: info: VolumeController:: Volume=0 Mute =true May 30 15:39:07 terrasse volumio[30883]: info: CoreStateMachine::pushState May 30 15:39:07 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::volumioPushState May 30 15:39:07 terrasse volumio[30982]: Starting albumart workers May 30 15:39:07 terrasse sudo[31093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 30 15:39:07 terrasse sudo[31093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:07 terrasse volumio[30883]: info: [squeezelite_mc] Server discovery started May 30 15:39:07 terrasse volumio[30883]: info: [squeezelite_mc] Player finder started May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: [squeezelite_mc] Executing aplay -D hw:3 --nonblock -f MPEG /dev/zero 2>&1 || true May 30 15:39:07 terrasse systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 30 15:39:07 terrasse systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 30 15:39:07 terrasse systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 30 15:39:07 terrasse go-librespot[31097]: go-librespot daemon starting... May 30 15:39:07 terrasse sudo[31093]: pam_unix(sudo:session): session closed for user root May 30 15:39:07 terrasse go-librespot[31100]: time="2026-05-30T15:39:07+02:00" level=info msg="running go-librespot 0.7.1" May 30 15:39:07 terrasse go-librespot[31100]: time="2026-05-30T15:39:07+02:00" level=debug msg="app state loaded" May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse go-librespot[31100]: time="2026-05-30T15:39:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:07 terrasse volumio[30883]: info: No need to fix Spotify hosts May 30 15:39:08 terrasse volumio[30883]: info: [squeezelite_mc] Card 3 supports the following ALSA formats: ["S16_LE","S24_LE","S32_LE"] May 30 15:39:08 terrasse volumio[30883]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"terrasse","dsdFormat":null,"card":"3","mixerType":"Hardware","mixer":"Analogue"} May 30 15:39:08 terrasse volumio[30883]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf May 30 15:39:08 terrasse sudo[31118]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf May 30 15:39:08 terrasse sudo[31118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:08 terrasse sudo[31118]: pam_unix(sudo:session): session closed for user root May 30 15:39:08 terrasse volumio[30883]: info: [squeezelite_mc] Executing alsactl -L -R nrestore May 30 15:39:08 terrasse sudo[31122]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore May 30 15:39:08 terrasse sudo[31122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:08 terrasse sudo[31122]: pam_unix(sudo:session): session closed for user root May 30 15:39:08 terrasse volumio[30883]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service May 30 15:39:08 terrasse sudo[31126]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service May 30 15:39:08 terrasse sudo[31126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:08 terrasse sudo[31126]: pam_unix(sudo:session): session closed for user root May 30 15:39:08 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true May 30 15:39:09 terrasse sudo[31135]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload May 30 15:39:09 terrasse sudo[31135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:09 terrasse systemd[1]: Reloading. May 30 15:39:11 terrasse volumio[30883]: info: go-librespot daemon successfully initialized May 30 15:39:11 terrasse 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. May 30 15:39:11 terrasse 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. May 30 15:39:11 terrasse sudo[31135]: pam_unix(sudo:session): session closed for user root May 30 15:39:11 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:39:12 terrasse sudo[31167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:39:12 terrasse sudo[31167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:12 terrasse sudo[31167]: pam_unix(sudo:session): session closed for user root May 30 15:39:12 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true May 30 15:39:12 terrasse sudo[31170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite May 30 15:39:12 terrasse sudo[31170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:12 terrasse systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... May 30 15:39:12 terrasse mpd[31086]: 2026-05-30T15:39:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 30 15:39:12 terrasse systemd[1]: Started mpd.service - Music Player Daemon. May 30 15:39:12 terrasse sudo[31045]: pam_unix(sudo:session): session closed for user root May 30 15:39:12 terrasse sudo[31030]: pam_unix(sudo:session): session closed for user root May 30 15:39:12 terrasse systemd[1]: squeezelite.service: Deactivated successfully. May 30 15:39:12 terrasse systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. May 30 15:39:12 terrasse systemd[1]: squeezelite.service: Consumed 1.293s CPU time. May 30 15:39:12 terrasse sudo[31170]: pam_unix(sudo:session): session closed for user root May 30 15:39:12 terrasse volumio[30883]: error: MPD error: The expression evaluated to a falsy value: May 30 15:39:12 terrasse volumio[30883]: assert.ok(self.idling) May 30 15:39:12 terrasse volumio[30883]: error: The expression evaluated to a falsy value: May 30 15:39:12 terrasse volumio[30883]: assert.ok(self.idling) May 30 15:39:12 terrasse volumio[30883]: error: updateQueue error: null May 30 15:39:12 terrasse volumio[30883]: info: MPD running with PID31086 May 30 15:39:12 terrasse volumio[30883]: ,establishing connection May 30 15:39:12 terrasse volumio[30883]: error: updateQueue error: null May 30 15:39:13 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:39:13 terrasse sudo[31178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:39:13 terrasse sudo[31178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:13 terrasse sudo[31178]: pam_unix(sudo:session): session closed for user root May 30 15:39:13 terrasse volumio[30883]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log May 30 15:39:13 terrasse sudo[31182]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log May 30 15:39:13 terrasse sudo[31182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:13 terrasse sudo[31182]: pam_unix(sudo:session): session closed for user root May 30 15:39:13 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true May 30 15:39:13 terrasse sudo[31185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite May 30 15:39:13 terrasse sudo[31185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:13 terrasse systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... May 30 15:39:13 terrasse systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. May 30 15:39:13 terrasse sudo[31185]: pam_unix(sudo:session): session closed for user root May 30 15:39:14 terrasse volumio[30883]: info: Initializing connection to go-librespot Websocket May 30 15:39:14 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:39:14 terrasse sudo[31192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:39:14 terrasse sudo[31192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:14 terrasse sudo[31192]: pam_unix(sudo:session): session closed for user root May 30 15:39:14 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:39:14 terrasse sudo[31195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:39:14 terrasse sudo[31195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:14 terrasse sudo[31195]: pam_unix(sudo:session): session closed for user root May 30 15:39:15 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:39:15 terrasse sudo[31212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:39:15 terrasse sudo[31212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:15 terrasse sudo[31212]: pam_unix(sudo:session): session closed for user root May 30 15:39:16 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:39:16 terrasse sudo[31215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:39:16 terrasse sudo[31215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:16 terrasse sudo[31215]: pam_unix(sudo:session): session closed for user root May 30 15:39:16 terrasse volumio[30883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:39:16 terrasse sudo[31218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:39:16 terrasse sudo[31218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:16 terrasse volumio[30883]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io May 30 15:39:16 terrasse sudo[31218]: pam_unix(sudo:session): session closed for user root May 30 15:39:16 terrasse volumio[30883]: info: Completed starting Core Plugins May 30 15:39:16 terrasse volumio[30883]: info: ------------------------------------------- May 30 15:39:16 terrasse volumio[30883]: info: ----- MyVolumio plugins startup ---- May 30 15:39:16 terrasse volumio[30883]: info: ------------------------------------------- May 30 15:39:16 terrasse volumio[30883]: info: [MyVolumio PluginManager] Fetching plans data.... May 30 15:39:17 terrasse volumio[30883]: verbose: New Socket.io Connection to 192.168.0.182:3000 from 192.168.0.181 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 30 15:39:17 terrasse volumio[30883]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 30 15:39:19 terrasse go-librespot[31100]: time="2026-05-30T15:39:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 30 15:39:19 terrasse systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 30 15:39:19 terrasse systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 30 15:39:20 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1133. May 30 15:39:20 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:20 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:20 terrasse upmpdcli[31220]: Could not open config: /tmp/upmpdcli.conf May 30 15:39:20 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:39:20 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:39:21 terrasse volumio[30883]: verbose: New Socket.io Connection to 192.168.0.182:3000 from 192.168.0.181 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 30 15:39:23 terrasse systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. May 30 15:39:23 terrasse systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 30 15:39:23 terrasse systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 30 15:39:23 terrasse go-librespot[31221]: go-librespot daemon starting... May 30 15:39:23 terrasse volumio[30883]: info: Discovery: adding f3d1f87f-51d5-484b-934b-2515db04a35c May 30 15:39:23 terrasse volumio[30883]: info: Discovery: Found device Terrasse May 30 15:39:23 terrasse volumio[30883]: info: CoreCommandRouter::volumioGetState May 30 15:39:23 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:23 terrasse volumio[30883]: info: Discovery: adding c892e03f-0f2f-4b0d-8a5e-5abb4ac349c1 May 30 15:39:23 terrasse volumio[30883]: info: Discovery: Found device OpenLounge May 30 15:39:23 terrasse volumio[30883]: info: Discovery: Connecting to remote: 192.168.0.181 May 30 15:39:23 terrasse go-librespot[31222]: time="2026-05-30T15:39:23+02:00" level=info msg="running go-librespot 0.7.1" May 30 15:39:23 terrasse go-librespot[31222]: time="2026-05-30T15:39:23+02:00" level=debug msg="app state loaded" May 30 15:39:23 terrasse volumio[30883]: info: Discovery: this is already registered, f3d1f87f-51d5-484b-934b-2515db04a35c May 30 15:39:23 terrasse volumio[30883]: info: Discovery: Found device Terrasse May 30 15:39:23 terrasse volumio[30883]: info: CoreCommandRouter::volumioGetState May 30 15:39:23 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:23 terrasse volumio[30883]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 30 15:39:23 terrasse go-librespot[31222]: time="2026-05-30T15:39:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 30 15:39:23 terrasse volumio[30883]: info: CoreCommandRouter::volumioGetState May 30 15:39:23 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:23 terrasse volumio[30883]: info: Discovery: Connected to remote: 192.168.0.181 May 30 15:39:26 terrasse volumio[30883]: info: Initializing connection to go-librespot Websocket May 30 15:39:26 terrasse go-librespot[31222]: time="2026-05-30T15:39:26+02:00" level=debug msg="new websocket client" May 30 15:39:26 terrasse volumio[30883]: info: Connection to go-librespot Websocket established May 30 15:39:26 terrasse volumio[30883]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.119&uuid=0c5105e38787e9becee8f277a1083452" http://updates.volumio.org/downloader-v1/track-device May 30 15:39:26 terrasse volumio[30883]: % Total % Received % Xferd Average Speed Time Time Time Current May 30 15:39:26 terrasse volumio[30883]: Dload Upload Total Spent Left Speed May 30 15:39:26 terrasse volumio[30883]: [922B blob data] May 30 15:39:26 terrasse volumio[30883]: retrying in 5 seconds, trial 0 May 30 15:39:26 terrasse volumio[30883]: info: Volumio Calling Home May 30 15:39:29 terrasse volumio[30883]: info: Getting Spotify volume May 30 15:39:29 terrasse volumio[30883]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 30 15:39:29 terrasse volumio[30883]: info: CoreCommandRouter::volumioGetState May 30 15:39:29 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:35 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1134. May 30 15:39:35 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:35 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:35 terrasse upmpdcli[31249]: Could not open config: /tmp/upmpdcli.conf May 30 15:39:35 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:39:35 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 15:39:36 terrasse volumio[30883]: error: MyVolumio Plugin failed to start in a timely fashion May 30 15:39:36 terrasse volumio[30883]: [Metrics] CommandRouter: 45s 673.80ms May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::volumiosetStartupVolume May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:39:36 terrasse volumio[30883]: info: VolumeController:: Setting startup Volume 40 May 30 15:39:36 terrasse volumio[30883]: info: VolumeController::SetAlsaVolume40 May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::Close All Modals sent May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::Close All Modals sent May 30 15:39:36 terrasse volumio[30883]: info: CoreStateMachine::pushState May 30 15:39:36 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::volumioPushState May 30 15:39:36 terrasse volumio[30883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 May 30 15:39:36 terrasse volumio[30883]: SPOTIFY: SPOTIFY VOLUME undefined May 30 15:39:36 terrasse volumio[30883]: SPOTIFY: VOLUMIO VOLUME 40 May 30 15:39:36 terrasse volumio[30883]: info: Aligning Spotify Volume to Volumio Volume May 30 15:39:36 terrasse volumio[30883]: info: CoreCommandRouter::volumioGetState May 30 15:39:36 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:36 terrasse volumio[30883]: info: Setting Spotify Volume from Volumio: 40 May 30 15:39:37 terrasse volumio[30883]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.0.38","name":"Music Assistant","ver":"7.999.999","uuid":"slimproto","jsonPort":"9000","cliPort":"9090"} May 30 15:39:37 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 30 15:39:37 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 15:39:37 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 30 15:39:38 terrasse volumio[30883]: SPOTIFY: SETTING SPOTIFY VOLUME 40 May 30 15:39:38 terrasse volumio[30883]: info: Sending Spotify command with payload to local API: /player/volume May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 30 15:39:38 terrasse volumio[30883]: info: Adding plugin bluetooth to MyMusic Plugins May 30 15:39:38 terrasse volumio[30883]: info: Adding plugin multiroom to MyMusic Plugins May 30 15:39:38 terrasse volumio[30883]: info: Adding plugin metavolumio to MyMusic Plugins May 30 15:39:38 terrasse volumio[30883]: info: Adding plugin cd_controller to MyMusic Plugins May 30 15:39:38 terrasse volumio[30883]: info: Adding plugin qobuzconnect to MyMusic Plugins May 30 15:39:38 terrasse volumio[30883]: info: Adding plugin smart_inputs to MyMusic Plugins May 30 15:39:38 terrasse volumio[30883]: info: Adding plugin tidalconnect to MyMusic Plugins May 30 15:39:38 terrasse volumio[30883]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02: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]" May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02: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]" May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02: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]" May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02:00" level=info msg="zeroconf server listening on port 38617" May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02:00" level=debug msg="obtained new client token: AADc167+4YhTcdKXC5MbJKJIxAhibHRH+L18ZuUb/Jv8TslAPD4mSlJm5zm3B477KUxS5I7ekXXbTxIQe7SmjsmnLUoqsQneOc7sic+HvXIy0Nl7luL31UM9yj5Gx+pB9Ul6mT86MYyv3Wl1uhV/hbuzg5/Nr1yvxTNgsCGz/dHxbJmq20kaxvTeQIbolQjAGqT6+ovOeM78CfA6fV6akMRv9Hp9/ihXYeAM6O6Jl95mQ/ud6hsd2mI=" May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 30 15:39:39 terrasse go-librespot[31222]: time="2026-05-30T15:39:39+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.0.182:38384->34.158.1.133:4070: read: connection reset by peer" May 30 15:39:40 terrasse volumio[30883]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 30 15:39:40 terrasse volumio[30883]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 30 15:39:40 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:40 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:39:40 terrasse volumio[30883]: info: Starting MyVolumio Remote Streaming Endpoints May 30 15:39:40 terrasse volumio[30883]: info: MyVolumio login type: Token May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=debug msg="completed keyexchange" May 30 15:39:40 terrasse volumio[30883]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=debug msg="completed challenge" May 30 15:39:40 terrasse volumio[30883]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=info msg="authenticated AP" username="ra**z7" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=info msg="authenticated Login5" username="ra**z7" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=debug msg="initializing zeroconf session" username="ra**z7" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=debug msg="dealer connection opened" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=trace msg="starting accesspoint recv loop" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=trace msg="starting dealer recv loop" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=trace msg="received accesspoint ping" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 30 15:39:40 terrasse go-librespot[31222]: time="2026-05-30T15:39:40+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 30 15:39:41 terrasse go-librespot[31222]: time="2026-05-30T15:39:41+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 30 15:39:41 terrasse go-librespot[31222]: time="2026-05-30T15:39:41+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 30 15:39:41 terrasse go-librespot[31222]: time="2026-05-30T15:39:41+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 30 15:39:41 terrasse go-librespot[31222]: time="2026-05-30T15:39:41+02:00" level=debug msg="received connection id: NWRjYTQ4ZTktZWJm...RjdDRTVCRTM3Mw==" May 30 15:39:41 terrasse go-librespot[31222]: time="2026-05-30T15:39:41+02:00" level=trace msg="received accesspoint pong ack" May 30 15:39:42 terrasse volumio[30883]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 30 15:39:42 terrasse volumio[30883]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 30 15:39:42 terrasse volumio[30883]: info: Streaming services startup May 30 15:39:42 terrasse volumio[30883]: info: Starting Streaming Daemon May 30 15:39:42 terrasse sudo[31269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 30 15:39:42 terrasse volumio[30883]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 30 15:39:42 terrasse sudo[31269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:42 terrasse sudo[31269]: pam_unix(sudo:session): session closed for user root May 30 15:39:42 terrasse volumio[30883]: info: Spotify volume: 100 May 30 15:39:42 terrasse volumio[30883]: error: Cannot start Volumio Streaming Daemon May 30 15:39:42 terrasse volumio[30883]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 30 15:39:42 terrasse volumio[30883]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 30 15:39:42 terrasse volumio[30883]: info: Volumio called home May 30 15:39:42 terrasse volumio[30883]: verbose: New Socket.io Connection to 192.168.0.182:3000 from 192.168.0.181 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 30 15:39:43 terrasse volumio[30883]: info: [squeezelite_mc] Notification listener started May 30 15:39:43 terrasse volumio[30883]: info: [squeezelite_mc] Getting players connected to Music Assistant (192.168.0.38) May 30 15:39:43 terrasse volumio[30883]: info: BOOT COMPLETED May 30 15:39:44 terrasse volumio[30883]: info: [squeezelite_mc] Players connected to Music Assistant (192.168.0.38): [{"id":"b8:27:eb:93:ba:5a","uuid":null,"ip":"192.168.0.181","name":"openlounge","server":{"ip":"192.168.0.38","name":"Music Assistant","ver":"7.999.999","uuid":"slimproto","jsonPort":"9000","cliPort":"9090"}},{"id":"b8:27:eb:25:61:84","uuid":null,"ip":"192.168.0.182","name":"terrasse","server":{"ip":"192.168.0.38","name":"Music Assistant","ver":"7.999.999","uuid":"slimproto","jsonPort":"9000","cliPort":"9090"}}] May 30 15:39:44 terrasse volumio[30883]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:25:61:84","uuid":null,"ip":"192.168.0.182","name":"terrasse","server":{"ip":"192.168.0.38","name":"Music Assistant","ver":"7.999.999","uuid":"slimproto","jsonPort":"9000","cliPort":"9090"}} May 30 15:39:44 terrasse volumio[30883]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 30 15:39:44 terrasse volumio[30883]: info: CoreCommandRouter::volumioGetState May 30 15:39:44 terrasse volumio[30883]: info: CorePlayQueue::getTrack 0 May 30 15:39:49 terrasse volumio[30883]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 15:39:49 terrasse volumio[30883]: NotificationListenerError: Failed to send server command 'subscribe play,stop,pause,playlist,mixer,sync'. May 30 15:39:49 terrasse volumio[30883]: at CommandQueue._CommandQueue_shiftAndExec (/data/plugins/music_service/squeezelite_mc/node_modules/lms-cli-notifications/dist/cjs/utils/CommandQueue.js:91:26) { May 30 15:39:49 terrasse volumio[30883]: code: -20, May 30 15:39:49 terrasse volumio[30883]: cause: Error: response not received May 30 15:39:49 terrasse volumio[30883]: at Timeout._onTimeout (/data/plugins/music_service/squeezelite_mc/node_modules/telnet-client/lib/index.js:297:48) May 30 15:39:49 terrasse volumio[30883]: at listOnTimeout (node:internal/timers:573:17) May 30 15:39:49 terrasse volumio[30883]: at process.processTimers (node:internal/timers:514:7) May 30 15:39:49 terrasse volumio[30883]: } May 30 15:39:49 terrasse volumio[30883]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 15:39:50 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1135. May 30 15:39:50 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:50 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:39:50 terrasse upmpdcli[31302]: Could not open config: /tmp/upmpdcli.conf May 30 15:39:50 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:39:50 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:39:50 terrasse sudo[31305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-30 15:38' May 30 15:39:50 terrasse sudo[31305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:39:51 terrasse sudo[31305]: pam_unix(sudo:session): session closed for user root May 30 15:39:59 terrasse go-librespot[31222]: time="2026-05-30T15:39:59+02:00" level=debug msg="put connect state because NEW_DEVICE" May 30 15:39:59 terrasse go-librespot[31222]: time="2026-05-30T15:39:59+02:00" level=debug msg="update volume requested to 26214/65535" May 30 15:40:01 terrasse go-librespot[31222]: time="2026-05-30T15:40:01+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 30 15:40:01 terrasse go-librespot[31222]: time="2026-05-30T15:40:01+02:00" level=trace msg="emitting websocket event: volume" May 30 15:40:01 terrasse go-librespot[31222]: time="2026-05-30T15:40:01+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: read tcp 127.0.0.1:9879->127.0.0.1:58632: read: connection reset by peer" May 30 15:40:01 terrasse volumio-remote-updater[594]: [2026-05-30 15:40:01] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) May 30 15:40:01 terrasse volumio-remote-updater[594]: [2026-05-30 15:40:01] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] May 30 15:40:01 terrasse volumio5-onboarding[1207]: time=2026-05-30T15:40:01.957+02:00 level=ERROR msg="failed reading message" error="read tcp 127.0.0.1:37360->127.0.0.1:3000: read: connection reset by peer" May 30 15:40:01 terrasse volumio5-onboarding[1207]: time=2026-05-30T15:40:01.960+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" May 30 15:40:01 terrasse systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 30 15:40:01 terrasse systemd[1]: volumio.service: Failed with result 'exit-code'. May 30 15:40:01 terrasse systemd[1]: volumio.service: Consumed 56.171s CPU time. May 30 15:40:02 terrasse systemd[1]: Started dynamicswap.service - dynamicswap service. May 30 15:40:02 terrasse systemd[1]: dynamicswap.service: Deactivated successfully. May 30 15:40:02 terrasse systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9. May 30 15:40:02 terrasse systemd[1]: Started dynamicswap.service - dynamicswap service. May 30 15:40:02 terrasse systemd[1]: Stopped volumio.service - Volumio Backend Module. May 30 15:40:02 terrasse systemd[1]: volumio.service: Consumed 56.171s CPU time. May 30 15:40:02 terrasse systemd[1]: Started volumio.service - Volumio Backend Module. May 30 15:40:02 terrasse systemd[1]: dynamicswap.service: Deactivated successfully. May 30 15:40:02 terrasse volumio5-onboarding[1207]: time=2026-05-30T15:40:02.962+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" May 30 15:40:03 terrasse volumio5-onboarding[1207]: time=2026-05-30T15:40:03.965+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" May 30 15:40:05 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1136. May 30 15:40:05 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:05 terrasse volumio[31343]: info: ------------------------------------------- May 30 15:40:05 terrasse volumio[31343]: info: ----- Volumio3 ---- May 30 15:40:05 terrasse volumio[31343]: info: ------------------------------------------- May 30 15:40:05 terrasse volumio[31343]: info: ----- System startup ---- May 30 15:40:05 terrasse volumio[31343]: info: ------------------------------------------- May 30 15:40:05 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:05 terrasse upmpdcli[31364]: Could not open config: /tmp/upmpdcli.conf May 30 15:40:06 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:40:06 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:40:06 terrasse volumio-remote-updater[594]: [2026-05-30 15:40:06] [connect] Successful connection May 30 15:40:07 terrasse volumio[31343]: info: MYVOLUMIO Environment detected May 30 15:40:07 terrasse volumio[31343]: info: Plugin folders cleanup May 30 15:40:07 terrasse volumio[31343]: info: Scanning into folder /volumio/app/plugins/ May 30 15:40:07 terrasse volumio[31343]: info: Scanning category audio_interface May 30 15:40:07 terrasse volumio[31343]: info: Scanning category miscellanea May 30 15:40:07 terrasse volumio[31343]: info: Scanning category music_service May 30 15:40:07 terrasse volumio[31343]: info: Scanning category plugins.json May 30 15:40:07 terrasse volumio[31343]: info: Scanning category system_controller May 30 15:40:07 terrasse volumio[31343]: info: Scanning category user_interface May 30 15:40:07 terrasse volumio[31343]: info: Scanning into folder /data/plugins/ May 30 15:40:07 terrasse volumio[31343]: info: Scanning category music_service May 30 15:40:07 terrasse volumio[31343]: info: Plugin folders cleanup completed May 30 15:40:07 terrasse volumio[31343]: info: ------------------------------------------- May 30 15:40:07 terrasse volumio[31343]: info: ----- Core plugins startup ---- May 30 15:40:07 terrasse volumio[31343]: info: ------------------------------------------- May 30 15:40:07 terrasse volumio[31343]: info: Loading plugins from folder /volumio/app/plugins/ May 30 15:40:07 terrasse volumio[31343]: info: Adding plugin upnp to MyMusic Plugins May 30 15:40:07 terrasse volumio[31343]: info: Adding plugin airplay_emulation to MyMusic Plugins May 30 15:40:07 terrasse volumio[31343]: info: Adding plugin upnp_browser to MyMusic Plugins May 30 15:40:07 terrasse volumio[31343]: info: Loading plugins from folder /data/plugins/ May 30 15:40:07 terrasse volumio[31343]: info: Loading plugin "system"... May 30 15:40:07 terrasse volumio[31343]: info: Loading plugin "appearance"... May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "network"... May 30 15:40:09 terrasse volumio[31343]: info: Refreshing Cached IP Addresses May 30 15:40:09 terrasse sudo[31373]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 30 15:40:09 terrasse sudo[31373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:09 terrasse sudo[31375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "services"... May 30 15:40:09 terrasse sudo[31375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:09 terrasse sudo[31373]: pam_unix(sudo:session): session closed for user root May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "volumio5onboarding"... May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "alsa_controller"... May 30 15:40:09 terrasse sudo[31382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 30 15:40:09 terrasse sudo[31382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:09 terrasse sudo[31375]: pam_unix(sudo:session): session closed for user root May 30 15:40:09 terrasse sudo[31382]: pam_unix(sudo:session): session closed for user root May 30 15:40:09 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "wizard"... May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "networkfs"... May 30 15:40:09 terrasse volumio[31343]: info: Starting Udev Watcher for removable devices May 30 15:40:09 terrasse volumio[31343]: info: Ignoring mount for partition: boot May 30 15:40:09 terrasse volumio[31343]: info: Ignoring mount for partition: volumio May 30 15:40:09 terrasse volumio[31343]: info: Ignoring mount for partition: volumio_data May 30 15:40:09 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "volumio_command_line_client"... May 30 15:40:09 terrasse volumio[31343]: info: Plugin upnp is not enabled May 30 15:40:09 terrasse volumio[31343]: info: Loading plugin "my_music"... May 30 15:40:10 terrasse volumio[31343]: info: Loading plugin "mpd"... May 30 15:40:10 terrasse volumio[31343]: info: Plugin upnp_browser is not enabled May 30 15:40:10 terrasse volumio[31343]: info: Loading plugin "alarm-clock"... May 30 15:40:10 terrasse go-librespot[31222]: time="2026-05-30T15:40:10+02:00" level=trace msg="sent dealer ping" May 30 15:40:11 terrasse volumio[31343]: info: Plugin airplay_emulation is not enabled May 30 15:40:11 terrasse volumio[31343]: info: Loading plugin "last_100"... May 30 15:40:11 terrasse volumio[31343]: info: Loading plugin "webradio"... May 30 15:40:12 terrasse go-librespot[31222]: time="2026-05-30T15:40:12+02:00" level=trace msg="received dealer pong" May 30 15:40:13 terrasse volumio[31343]: info: Loading plugin "i2s_dacs"... May 30 15:40:13 terrasse volumio[31343]: info: Loading plugin "volumiodiscovery"... May 30 15:40:13 terrasse volumio[31343]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 30 15:40:13 terrasse volumio[31343]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 15:40:13 terrasse volumio[31343]: *** WARNING *** For more information see May 30 15:40:13 terrasse volumio[31343]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 30 15:40:13 terrasse volumio[31343]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 15:40:13 terrasse node[31343]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 30 15:40:13 terrasse volumio[31343]: *** WARNING *** For more information see May 30 15:40:13 terrasse node[31343]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 15:40:13 terrasse node[31343]: *** WARNING *** For more information see May 30 15:40:13 terrasse node[31343]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 30 15:40:13 terrasse node[31343]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 15:40:13 terrasse node[31343]: *** WARNING *** For more information see May 30 15:40:13 terrasse volumio[31343]: info: Applying required configuration parameters for plugin volumiodiscovery May 30 15:40:13 terrasse volumio[31343]: info: Discovery: Started advertising with name: Terrasse May 30 15:40:13 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 30 15:40:13 terrasse volumio[31343]: info: Loading plugin "spop"... May 30 15:40:14 terrasse volumio5-onboarding[1207]: time=2026-05-30T15:40:14.968+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:56752->127.0.0.1:3000: i/o timeout" May 30 15:40:15 terrasse volumio[31343]: info: Loading plugin "squeezelite_mc"... May 30 15:40:16 terrasse volumio[31343]: info: Loading plugin "outputs"... May 30 15:40:16 terrasse volumio[31343]: info: Loading plugin "albumart"... May 30 15:40:16 terrasse volumio[31343]: info: Plugin example_plugin is not enabled May 30 15:40:16 terrasse volumio[31343]: info: Loading plugin "inputs"... May 30 15:40:16 terrasse volumio[31343]: info: Loading plugin "updater_comm"... May 30 15:40:16 terrasse volumio[31343]: info: Plugin mpdemulation is not enabled May 30 15:40:16 terrasse volumio[31343]: info: Loading plugin "rest_api"... May 30 15:40:16 terrasse volumio[31343]: info: Loading plugin "websocket"... May 30 15:40:16 terrasse volumio[31343]: info: Starting Socket.io Server version 1.7.4 May 30 15:40:17 terrasse volumio[31343]: info: Loading i18n strings for locale de May 30 15:40:17 terrasse volumio[31343]: Updating browse sources language May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::initPlayerControls May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 15:40:17 terrasse volumio[31343]: Express server listening on port 3000 May 30 15:40:17 terrasse volumio[31343]: [Metrics] WebUI: 12s 506.26ms May 30 15:40:17 terrasse volumio[31343]: info: CoreStateMachine::resetVolumioState May 30 15:40:17 terrasse volumio[31343]: info: CoreStateMachine::getcurrentVolume May 30 15:40:17 terrasse volumio[31343]: info: CoreCommandRouter::volumioRetrievevolume May 30 15:40:17 terrasse volumio[31343]: info: Cannot read play queue from file May 30 15:40:17 terrasse volumio[31343]: info: Volumio Network Manager: Network status updated: 1 May 30 15:40:17 terrasse volumio[31343]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 30 15:40:17 terrasse volumio[31343]: wlan0 Interface doesn't support scanning. May 30 15:40:17 terrasse volumio[31343]: info: Cannot use regular scanning, forcing with ap-force May 30 15:40:17 terrasse sudo[31429]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 30 15:40:17 terrasse sudo[31429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:17 terrasse sudo[31429]: pam_unix(sudo:session): session closed for user root May 30 15:40:17 terrasse volumio[31343]: command failed: No such device (-19) May 30 15:40:17 terrasse volumio[31343]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 30 15:40:17 terrasse volumio[31343]: command failed: No such device (-19) May 30 15:40:17 terrasse volumio[31412]: Forking 3 albumart workers May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:40:18 terrasse volumio[31343]: info: Executing start script for DAC IQaudIO DAC Plus May 30 15:40:18 terrasse volumio[31343]: info: VolumeController:: Volume=0 Mute =true May 30 15:40:18 terrasse volumio[31343]: info: CoreStateMachine::pushState May 30 15:40:18 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioPushState May 30 15:40:18 terrasse volumio[31343]: info: CoreStateMachine::updateTrackBlock May 30 15:40:18 terrasse volumio[31343]: info: CorePlayQueue::getTrackBlock May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioRetrievevolume May 30 15:40:18 terrasse volumio[31343]: info: CoreStateMachine::setRepeat null single undefined May 30 15:40:18 terrasse volumio[31343]: info: CoreStateMachine::pushState May 30 15:40:18 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioPushState May 30 15:40:18 terrasse volumio[31343]: info: CoreStateMachine::setRandom null May 30 15:40:18 terrasse volumio[31343]: info: CoreStateMachine::pushState May 30 15:40:18 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioPushState May 30 15:40:18 terrasse volumio[31343]: info: Setting Device type: Raspberry PI May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioGetState May 30 15:40:18 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:18 terrasse volumio[31343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 May 30 15:40:18 terrasse volumio[31343]: info: DAC script executed May 30 15:40:18 terrasse volumio[31343]: info: Completed loading Core Plugins May 30 15:40:18 terrasse volumio[31343]: info: Preparing to generate the ALSA configuration file May 30 15:40:18 terrasse volumio[31343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 May 30 15:40:18 terrasse volumio[31343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 May 30 15:40:18 terrasse volumio[31343]: info: VolumeController:: Volume=0 Mute =true May 30 15:40:18 terrasse volumio[31343]: info: CoreStateMachine::pushState May 30 15:40:18 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioPushState May 30 15:40:18 terrasse volumio[31343]: info: Asound.conf file unchanged, so no further update is needed May 30 15:40:18 terrasse volumio[31343]: info: Output device has changed, restarting MPD May 30 15:40:18 terrasse volumio[31343]: info: ___________ START PLUGINS ___________ May 30 15:40:18 terrasse volumio[31343]: info: ControllerMpd::onStart: Initializing MPD May 30 15:40:18 terrasse volumio[31343]: info: Creating MPD Configuration file May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 15:40:18 terrasse volumio[31343]: info: [1780148418963] CoreMusicLibrary::Adding element Last_100 May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:40:18 terrasse sudo[31478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 15:40:18 terrasse volumio[31343]: info: [1780148418978] CoreMusicLibrary::Adding element Webradio May 30 15:40:18 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 15:40:18 terrasse sudo[31478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:18 terrasse sudo[31480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 15:40:18 terrasse sudo[31480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:19 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 15:40:19 terrasse sudo[31478]: pam_unix(sudo:session): session closed for user root May 30 15:40:19 terrasse volumio[31343]: info: Initializing BBC Radios May 30 15:40:19 terrasse sudo[31482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service May 30 15:40:19 terrasse sudo[31484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 15:40:19 terrasse sudo[31482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:19 terrasse sudo[31484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:19 terrasse sudo[31484]: pam_unix(sudo:session): session closed for user root May 30 15:40:19 terrasse sudo[31486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 15:40:19 terrasse sudo[31486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:19 terrasse systemd[1]: Stopping mpd.service - Music Player Daemon... May 30 15:40:19 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 15:40:19 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:40:19 terrasse sudo[31482]: pam_unix(sudo:session): session closed for user root May 30 15:40:19 terrasse systemd[1]: mpd.service: Deactivated successfully. May 30 15:40:19 terrasse systemd[1]: Stopped mpd.service - Music Player Daemon. May 30 15:40:19 terrasse systemd[1]: mpd.service: Consumed 6.830s CPU time. May 30 15:40:19 terrasse volumio[31343]: info: Creating Spotify config file May 30 15:40:19 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:19 terrasse systemd[1]: mpd.socket: Deactivated successfully. May 30 15:40:19 terrasse systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 30 15:40:19 terrasse systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 30 15:40:19 terrasse systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 15:40:19 terrasse systemd[1]: Starting mpd.service - Music Player Daemon... May 30 15:40:19 terrasse volumio-remote-updater[594]: [2026-05-30 15:40:19] [connect] Successful connection May 30 15:40:19 terrasse systemd[1]: mpd.service: Deactivated successfully. May 30 15:40:19 terrasse systemd[1]: Stopped mpd.service - Music Player Daemon. May 30 15:40:19 terrasse systemd[1]: mpd.socket: Deactivated successfully. May 30 15:40:19 terrasse systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 30 15:40:19 terrasse systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 30 15:40:19 terrasse systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 15:40:19 terrasse systemd[1]: Starting mpd.service - Music Player Daemon... May 30 15:40:20 terrasse sudo[31509]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 30 15:40:20 terrasse sudo[31509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 15:40:20 terrasse sudo[31509]: pam_unix(sudo:session): session closed for user root May 30 15:40:20 terrasse volumio[31343]: info: [squeezelite_mc] Starting proxy server... May 30 15:40:20 terrasse volumio[31343]: info: Volumio Calling Home May 30 15:40:20 terrasse volumio[31343]: info: [squeezelite_mc] Proxy server started on port 42541 May 30 15:40:21 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1137. May 30 15:40:21 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:21 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:21 terrasse upmpdcli[31529]: Could not open config: /tmp/upmpdcli.conf May 30 15:40:21 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:40:21 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:40:21 terrasse volumio[31435]: Starting albumart workers May 30 15:40:21 terrasse volumio[31343]: info: CoreCommandRouter::volumioRetrievevolume May 30 15:40:21 terrasse volumio[31343]: info: MPD Permissions set May 30 15:40:21 terrasse volumio[31343]: info: MPD Permissions set May 30 15:40:21 terrasse volumio-remote-updater[594]: [2026-05-30 15:40:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1780148419 101 May 30 15:40:21 terrasse volumio[31343]: 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 May 30 15:40:21 terrasse volumio[31343]: info: Spotify config file written May 30 15:40:21 terrasse volumio[31343]: info: VolumeController:: Volume=0 Mute =true May 30 15:40:21 terrasse volumio[31343]: info: CoreStateMachine::pushState May 30 15:40:21 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:21 terrasse volumio[31343]: info: CoreCommandRouter::volumioPushState May 30 15:40:21 terrasse volumio[31343]: info: [squeezelite_mc] Server discovery started May 30 15:40:21 terrasse volumio[31343]: info: [squeezelite_mc] Player finder started May 30 15:40:21 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:21 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:21 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:21 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 15:40:21 terrasse volumio[31343]: info: [squeezelite_mc] Executing aplay -D hw:3 --nonblock -f MPEG /dev/zero 2>&1 || true May 30 15:40:21 terrasse volumio[31433]: Starting albumart workers May 30 15:40:22 terrasse sudo[31533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 30 15:40:22 terrasse sudo[31533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 30 15:40:22 terrasse systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 30 15:40:22 terrasse systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:40:22 terrasse systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 30 15:40:22 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 15:40:22 terrasse go-librespot[31547]: go-librespot daemon starting... May 30 15:40:22 terrasse volumio[31343]: info: No need to fix Spotify hosts May 30 15:40:22 terrasse sudo[31533]: pam_unix(sudo:session): session closed for user root May 30 15:40:22 terrasse volumio[31343]: info: [squeezelite_mc] Card 3 supports the following ALSA formats: ["S16_LE","S24_LE","S32_LE"] May 30 15:40:22 terrasse volumio[31343]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"terrasse","dsdFormat":null,"card":"3","mixerType":"Hardware","mixer":"Analogue"} May 30 15:40:22 terrasse go-librespot[31548]: time="2026-05-30T15:40:22+02:00" level=info msg="running go-librespot 0.7.1" May 30 15:40:22 terrasse go-librespot[31548]: time="2026-05-30T15:40:22+02:00" level=debug msg="app state loaded" May 30 15:40:22 terrasse volumio[31343]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf May 30 15:40:22 terrasse go-librespot[31548]: time="2026-05-30T15:40:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 30 15:40:22 terrasse volumio[31434]: Starting albumart workers May 30 15:40:22 terrasse sudo[31559]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf May 30 15:40:22 terrasse sudo[31559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:22 terrasse sudo[31559]: pam_unix(sudo:session): session closed for user root May 30 15:40:22 terrasse volumio[31343]: info: [squeezelite_mc] Executing alsactl -L -R nrestore May 30 15:40:22 terrasse sudo[31563]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore May 30 15:40:22 terrasse sudo[31563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:22 terrasse sudo[31563]: pam_unix(sudo:session): session closed for user root May 30 15:40:22 terrasse volumio[31343]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service May 30 15:40:22 terrasse sudo[31567]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service May 30 15:40:22 terrasse sudo[31567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:22 terrasse sudo[31567]: pam_unix(sudo:session): session closed for user root May 30 15:40:23 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true May 30 15:40:23 terrasse sudo[31570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload May 30 15:40:23 terrasse sudo[31570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:23 terrasse systemd[1]: Reloading. May 30 15:40:25 terrasse volumio[31343]: info: go-librespot daemon successfully initialized May 30 15:40:26 terrasse 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. May 30 15:40:26 terrasse 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. May 30 15:40:26 terrasse sudo[31570]: pam_unix(sudo:session): session closed for user root May 30 15:40:26 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:40:26 terrasse sudo[31608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:40:26 terrasse sudo[31608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:26 terrasse sudo[31608]: pam_unix(sudo:session): session closed for user root May 30 15:40:26 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true May 30 15:40:26 terrasse sudo[31611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite May 30 15:40:26 terrasse sudo[31611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:26 terrasse systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... May 30 15:40:26 terrasse mpd[31525]: 2026-05-30T15:40:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 30 15:40:26 terrasse systemd[1]: Started mpd.service - Music Player Daemon. May 30 15:40:26 terrasse sudo[31480]: pam_unix(sudo:session): session closed for user root May 30 15:40:26 terrasse sudo[31486]: pam_unix(sudo:session): session closed for user root May 30 15:40:26 terrasse systemd[1]: squeezelite.service: Deactivated successfully. May 30 15:40:26 terrasse systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. May 30 15:40:27 terrasse sudo[31611]: pam_unix(sudo:session): session closed for user root May 30 15:40:27 terrasse volumio[31343]: error: MPD error: The expression evaluated to a falsy value: May 30 15:40:27 terrasse volumio[31343]: assert.ok(self.idling) May 30 15:40:27 terrasse volumio[31343]: error: The expression evaluated to a falsy value: May 30 15:40:27 terrasse volumio[31343]: assert.ok(self.idling) May 30 15:40:27 terrasse volumio[31343]: info: MPD running with PID31525 May 30 15:40:27 terrasse volumio[31343]: ,establishing connection May 30 15:40:27 terrasse volumio[31343]: error: updateQueue error: null May 30 15:40:27 terrasse volumio[31343]: error: updateQueue error: null May 30 15:40:27 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:40:27 terrasse sudo[31618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:40:27 terrasse sudo[31618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:27 terrasse sudo[31618]: pam_unix(sudo:session): session closed for user root May 30 15:40:27 terrasse volumio[31343]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log May 30 15:40:27 terrasse sudo[31622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log May 30 15:40:27 terrasse sudo[31622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:27 terrasse sudo[31622]: pam_unix(sudo:session): session closed for user root May 30 15:40:27 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true May 30 15:40:27 terrasse sudo[31625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite May 30 15:40:27 terrasse sudo[31625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:28 terrasse systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... May 30 15:40:28 terrasse systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. May 30 15:40:28 terrasse sudo[31625]: pam_unix(sudo:session): session closed for user root May 30 15:40:28 terrasse volumio[31343]: info: Initializing connection to go-librespot Websocket May 30 15:40:28 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:40:28 terrasse sudo[31632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:40:28 terrasse sudo[31632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:28 terrasse sudo[31632]: pam_unix(sudo:session): session closed for user root May 30 15:40:29 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:40:29 terrasse sudo[31635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:40:29 terrasse sudo[31635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:29 terrasse sudo[31635]: pam_unix(sudo:session): session closed for user root May 30 15:40:29 terrasse volumio[31343]: verbose: New Socket.io Connection to 192.168.0.182:3000 from 192.168.0.181 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 30 15:40:29 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket May 30 15:40:29 terrasse volumio[31343]: info: CoreCommandRouter::volumioGetState May 30 15:40:29 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:29 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:40:29 terrasse sudo[31638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:40:29 terrasse sudo[31638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:30 terrasse sudo[31638]: pam_unix(sudo:session): session closed for user root May 30 15:40:30 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:40:30 terrasse sudo[31656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:40:30 terrasse sudo[31656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:30 terrasse sudo[31656]: pam_unix(sudo:session): session closed for user root May 30 15:40:31 terrasse volumio[31343]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true May 30 15:40:31 terrasse sudo[31659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite May 30 15:40:31 terrasse sudo[31659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:31 terrasse sudo[31659]: pam_unix(sudo:session): session closed for user root May 30 15:40:31 terrasse volumio[31343]: info: Completed starting Core Plugins May 30 15:40:31 terrasse volumio[31343]: info: ------------------------------------------- May 30 15:40:31 terrasse volumio[31343]: info: ----- MyVolumio plugins startup ---- May 30 15:40:31 terrasse volumio[31343]: info: ------------------------------------------- May 30 15:40:31 terrasse volumio[31343]: info: [MyVolumio PluginManager] Fetching plans data.... May 30 15:40:31 terrasse volumio[31343]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 30 15:40:36 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1138. May 30 15:40:36 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:36 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:36 terrasse upmpdcli[31661]: Could not open config: /tmp/upmpdcli.conf May 30 15:40:36 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:40:36 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:40:37 terrasse volumio[31343]: info: Discovery: adding c892e03f-0f2f-4b0d-8a5e-5abb4ac349c1 May 30 15:40:37 terrasse volumio[31343]: info: Discovery: Found device OpenLounge May 30 15:40:37 terrasse volumio[31343]: info: Discovery: Connecting to remote: 192.168.0.181 May 30 15:40:37 terrasse volumio[31343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 30 15:40:37 terrasse volumio[31343]: info: Discovery: adding f3d1f87f-51d5-484b-934b-2515db04a35c May 30 15:40:37 terrasse volumio[31343]: info: Discovery: Found device Terrasse May 30 15:40:37 terrasse volumio[31343]: info: CoreCommandRouter::volumioGetState May 30 15:40:37 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:37 terrasse volumio[31343]: info: Discovery: this is already registered, f3d1f87f-51d5-484b-934b-2515db04a35c May 30 15:40:37 terrasse volumio[31343]: info: Discovery: Found device Terrasse May 30 15:40:37 terrasse volumio[31343]: info: CoreCommandRouter::volumioGetState May 30 15:40:37 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:37 terrasse go-librespot[31548]: time="2026-05-30T15:40:37+02:00" level=debug msg="new websocket client" May 30 15:40:38 terrasse volumio[31343]: info: Connection to go-librespot Websocket established May 30 15:40:38 terrasse volumio[31343]: info: Discovery: Connected to remote: 192.168.0.181 May 30 15:40:38 terrasse volumio[31343]: info: CoreCommandRouter::volumioGetState May 30 15:40:38 terrasse volumio[31343]: info: CorePlayQueue::getTrack 0 May 30 15:40:39 terrasse volumio[31343]: verbose: New Socket.io Connection to 192.168.0.182:3000 from 192.168.0.181 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 30 15:40:39 terrasse volumio[31343]: info: New Spotify access tokenBQBjBkZDcF... May 30 15:40:40 terrasse volumio[31343]: info: Spotify credentials grant success - running version from March 24, 2019 May 30 15:40:40 terrasse volumio[31343]: verbose: New Socket.io Connection to 192.168.0.182:3000 from 192.168.0.181 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 30 15:40:40 terrasse volumio[31343]: info: Volumio called home May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 30 15:40:40 terrasse volumio[31343]: info: Adding plugin bluetooth to MyMusic Plugins May 30 15:40:40 terrasse volumio[31343]: info: Adding plugin multiroom to MyMusic Plugins May 30 15:40:40 terrasse volumio[31343]: info: Adding plugin metavolumio to MyMusic Plugins May 30 15:40:40 terrasse volumio[31343]: info: Adding plugin cd_controller to MyMusic Plugins May 30 15:40:40 terrasse volumio[31343]: info: Adding plugin qobuzconnect to MyMusic Plugins May 30 15:40:40 terrasse volumio[31343]: info: Adding plugin smart_inputs to MyMusic Plugins May 30 15:40:40 terrasse volumio[31343]: info: Adding plugin tidalconnect to MyMusic Plugins May 30 15:40:40 terrasse volumio[31343]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 30 15:40:41 terrasse volumio[31343]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 30 15:40:41 terrasse volumio[31343]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 30 15:40:41 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:40:41 terrasse volumio[31343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 15:40:41 terrasse volumio[31343]: info: Starting MyVolumio Remote Streaming Endpoints May 30 15:40:42 terrasse volumio[31343]: info: MyVolumio login type: Token May 30 15:40:42 terrasse volumio[31343]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 30 15:40:42 terrasse volumio[31343]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 30 15:40:43 terrasse volumio[31343]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 30 15:40:43 terrasse volumio[31343]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 30 15:40:43 terrasse volumio[31343]: info: Streaming services startup May 30 15:40:43 terrasse volumio[31343]: info: Starting Streaming Daemon May 30 15:40:43 terrasse sudo[31677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 30 15:40:43 terrasse volumio[31343]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 30 15:40:43 terrasse sudo[31677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 15:40:43 terrasse sudo[31677]: pam_unix(sudo:session): session closed for user root May 30 15:40:44 terrasse volumio[31343]: info: Getting Spotify volume May 30 15:40:44 terrasse volumio[31343]: error: Cannot start Volumio Streaming Daemon May 30 15:40:44 terrasse volumio[31343]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 30 15:40:44 terrasse volumio[31343]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 30 15:40:44 terrasse volumio[31343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 30 15:40:50 terrasse go-librespot[31548]: time="2026-05-30T15:40:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 30 15:40:50 terrasse volumio[31343]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 15:40:50 terrasse systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 30 15:40:50 terrasse systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 30 15:40:50 terrasse volumio[31343]: Error: socket hang up May 30 15:40:50 terrasse volumio[31343]: at connResetException (node:internal/errors:720:14) May 30 15:40:50 terrasse volumio[31343]: at Socket.socketOnEnd (node:_http_client:519:23) May 30 15:40:50 terrasse volumio[31343]: at Socket.emit (node:events:526:35) May 30 15:40:50 terrasse volumio[31343]: at endReadableNT (node:internal/streams/readable:1376:12) May 30 15:40:50 terrasse volumio[31343]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { May 30 15:40:50 terrasse volumio[31343]: code: 'ECONNRESET', May 30 15:40:50 terrasse volumio[31343]: response: undefined May 30 15:40:50 terrasse volumio[31343]: } May 30 15:40:50 terrasse volumio[31343]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 15:40:51 terrasse systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1139. May 30 15:40:51 terrasse systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:51 terrasse systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 15:40:51 terrasse upmpdcli[31710]: Could not open config: /tmp/upmpdcli.conf May 30 15:40:51 terrasse systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 15:40:51 terrasse systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 15:40:52 terrasse sudo[31713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-30 15:39' May 30 15:40:52 terrasse sudo[31713]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"