Dec 21 15:11:00 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:11:00+01:00" level=trace msg="sent dealer ping" Dec 21 15:11:00 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:11:00+01:00" level=trace msg="received dealer pong" Dec 21 15:11:07 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 478. Dec 21 15:11:07 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:07 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:07 volumio3840x2160 upmpdcli[15885]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:11:07 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:11:07 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:11:15 volumio3840x2160 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 21 15:11:16 volumio3840x2160 systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 21 15:11:16 volumio3840x2160 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 21 15:11:22 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 479. Dec 21 15:11:22 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:22 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:22 volumio3840x2160 upmpdcli[15941]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:11:22 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:11:22 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:11:23 volumio3840x2160 volumio[1366]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 14 Dec 21 15:11:23 volumio3840x2160 volumio[1366]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 14 Dec 21 15:11:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:11:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:11:30 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:11:30+01:00" level=trace msg="sent dealer ping" Dec 21 15:11:30 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:11:30+01:00" level=trace msg="received dealer pong" Dec 21 15:11:37 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 480. Dec 21 15:11:37 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:37 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:37 volumio3840x2160 upmpdcli[15965]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:11:37 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:11:37 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:11:49 volumio3840x2160 volumio[1366]: info: CALLMETHOD: user_interface peppy_screensaver saveVUMeterConf [object Object] Dec 21 15:11:49 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , saveVUMeterConf Dec 21 15:11:49 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 21 15:11:50 volumio3840x2160 volumio[1366]: info: peppy_screensaver: Start PeppyMeter Dec 21 15:11:51 volumio3840x2160 volumio[1366]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 14 Dec 21 15:11:51 volumio3840x2160 volumio[1366]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 14 Dec 21 15:11:51 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:11:51 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:11:53 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 481. Dec 21 15:11:53 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:53 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:11:53 volumio3840x2160 upmpdcli[16030]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:11:53 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:11:53 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:12:00 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:12:00+01:00" level=trace msg="received accesspoint ping" Dec 21 15:12:00 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:12:00+01:00" level=trace msg="received accesspoint pong ack" Dec 21 15:12:00 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:12:00+01:00" level=trace msg="sent dealer ping" Dec 21 15:12:00 volumio3840x2160 go-librespot[2191]: time="2025-12-21T15:12:00+01:00" level=trace msg="received dealer pong" Dec 21 15:12:08 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 482. Dec 21 15:12:08 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:12:08 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:12:08 volumio3840x2160 upmpdcli[16046]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:12:08 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:08 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: Prefetching next song Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: DOING PREFETCH IN MPD Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B3 Moonlight, Wrapped Around Us.flac" Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: Dec 21 15:12:10 volumio3840x2160 volumio[1366]: ---------------------------- MPD announces system playlist update Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: Ignoring MPD Status Update Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B3 Moonlight, Wrapped Around Us.flac" took 4 milliseconds Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand consume 1 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: ------------------------------ 3ms Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: sendMpdCommand consume 1 took 1 milliseconds Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreStateMachine::stPlaybackTimer Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreStateMachine::servicePause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: ControllerMpd::pause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand pause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: Dec 21 15:12:10 volumio3840x2160 volumio[1366]: ---------------------------- MPD announces state update: player Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: sendMpdCommand pause took 4 milliseconds Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: ControllerMpd::getState Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: sendMpdCommand status took 1 milliseconds Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseState Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: ControllerMpd::pushState Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":201376,"duration":204,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5608 Kbps","isStreaming":false,"title":"Skin And Skin","artist":"Andreas Vollenweider","album":"... Behind The Gardens - Behind The Wall - Under The Tree ... [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B2 Skin And Skin.flac","trackType":"flac"} Dec 21 15:12:10 volumio3840x2160 volumio[1366]: verbose: CURRENT POSITION 3 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState stateService pause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState currentStatus pause Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: CoreStateMachine::stPlaybackTimer Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: ------------------------------ 14ms Dec 21 15:12:10 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:10 volumio3840x2160 volumio[1366]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 21 15:12:11 volumio3840x2160 volumio[1366]: info: peppy_screensaver: Start PeppyMeter Dec 21 15:12:18 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 21 15:12:18 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::stop Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::updateTrackBlock Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrackBlock Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::stPlaybackTimer Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::serviceStop Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::serviceStop Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: ControllerMpd::stop Dec 21 15:12:23 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Disabling plugin peppy_screensaver Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Preparing to generate the ALSA configuration file Dec 21 15:12:23 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Dec 21 15:12:23 volumio3840x2160 volumio[1366]: ---------------------------- MPD announces state update: player Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: sendMpdCommand stop took 15 milliseconds Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: ControllerMpd::getState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Reading ALSA contributions from plugins. Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: sendMpdCommand status took 9 milliseconds Dec 21 15:12:23 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 21 15:12:23 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: ControllerMpd::pushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Skin And Skin","artist":"Andreas Vollenweider","album":"... Behind The Gardens - Behind The Wall - Under The Tree ... [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B2 Skin And Skin.flac","trackType":"flac"} Dec 21 15:12:23 volumio3840x2160 volumio[1366]: verbose: CURRENT POSITION 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState stateService stop Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState currentStatus stop Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: No code Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: ------------------------------ 21ms Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Creating Spotify config file Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Spotify config file written Dec 21 15:12:23 volumio3840x2160 sudo[16087]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Asound.conf file written Dec 21 15:12:23 volumio3840x2160 sudo[16087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Dec 21 15:12:23 volumio3840x2160 sudo[16087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 systemd[1]: volumio-app-plugins-music_service-mpd-mpd.conf.tmpl.mount: Deactivated successfully. Dec 21 15:12:23 volumio3840x2160 sudo[16087]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 483. Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:12:23 volumio3840x2160 sudo[16089]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 sudo[16089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 21 15:12:23 volumio3840x2160 sudo[16089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 sudo[16093]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 sudo[16093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 21 15:12:23 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:12:23 volumio3840x2160 sudo[16093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 21 15:12:23 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Killing process 2197 (go-librespot) with signal SIGKILL. Dec 21 15:12:23 volumio3840x2160 sudo[16093]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 volumio[1366]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 21 15:12:23 volumio3840x2160 upmpdcli[16101]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:23 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Consumed 1.338s CPU time. Dec 21 15:12:23 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:23 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:23 volumio3840x2160 go-librespot[16107]: go-librespot daemon starting... Dec 21 15:12:23 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:12:23 volumio3840x2160 sudo[16089]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="app state loaded" Dec 21 15:12:23 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Output device has changed, restarting MPD Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:23 volumio3840x2160 vtcs[2375]: [2025-12-21 15:12:23.552] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 21 15:12:23 volumio3840x2160 vtcs[2375]: [2025-12-21 15:12:23.552] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Done. Dec 21 15:12:23 volumio3840x2160 sudo[16118]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 sudo[16118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:12:23 volumio3840x2160 sudo[16118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 sudo[16120]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 sudo[16118]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 sudo[16120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:12:23 volumio3840x2160 sudo[16120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: Connection to go-librespot Websocket closed Dec 21 15:12:23 volumio3840x2160 sudo[16124]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 sudo[16124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:23 volumio3840x2160 sudo[16124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 21 15:12:23 volumio3840x2160 sudo[16126]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 21 15:12:23 volumio3840x2160 sudo[16126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:23 volumio3840x2160 sudo[16126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 systemd[1]: vtcs.service: Killing process 2382 (vtcs) with signal SIGKILL. Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: MPD Permissions set Dec 21 15:12:23 volumio3840x2160 systemd[1]: vtcs.service: Deactivated successfully. Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 21 15:12:23 volumio3840x2160 systemd[1]: vtcs.service: Consumed 3.061s CPU time. Dec 21 15:12:23 volumio3840x2160 sudo[16133]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 sudo[16133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 21 15:12:23 volumio3840x2160 sudo[16133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 sudo[16126]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 sudo[16124]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 sudo[16133]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:12:23 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:23 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:12:23 volumio3840x2160 systemd[1]: mpd.service: Consumed 3min 27.751s CPU time. Dec 21 15:12:23 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:12:23 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=info msg="zeroconf server listening on port 39423" Dec 21 15:12:23 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:12:23 volumio3840x2160 sudo[16148]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:12:23 volumio3840x2160 sudo[16148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 21 15:12:23 volumio3840x2160 sudo[16148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:23 volumio3840x2160 systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 21 15:12:23 volumio3840x2160 qobuz-connect[2353]: 20251221 15:12:23.735 [2353.2353] INFO SampleApp: Stopping Local configuration server Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="obtained new client token: AACGblZv6a2xccBntTCMTyYQvszKhE7YSP8i5BIIz1Zl4pIiDAEnc0ivQpPSZwl1mRw0wk7APOMmRZMGn4c1FAqGuVWXYzNIHxrQBxDoS/oQnSnib29GEIqqaKiUBcvl22aWdJq2OhmUU3ZRwpOfmQ0UaY6dD61dVW9dMKYis62nF4K5b+LBALR2Qj1byDYkhx4kQqzqdCGsPTUSAz2Fc9Ec06BgYy3wXar9R24Np+kAIFCNc6YCu7IR+w==" Dec 21 15:12:23 volumio3840x2160 sudo[16150]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 sudo[16150]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:23 volumio3840x2160 sudo[16150]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:12:23 volumio3840x2160 sudo[16150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:12:23 volumio3840x2160 sudo[16150]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="completed keyexchange" Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=debug msg="completed challenge" Dec 21 15:12:23 volumio3840x2160 go-librespot[16108]: time="2025-12-21T15:12:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Dec 21 15:12:23 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:23 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:24 volumio3840x2160 qobuz-connect[2353]: 20251221 15:12:24.219 [2353.2353] INFO SampleApp: shat down connection on UNIX socket Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:24 volumio3840x2160 systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 21 15:12:24 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:12:24 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:12:24 volumio3840x2160 sudo[16148]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: Executing endpoint qc_getconfig Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.289 [16154.16154] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.294 [16154.16154] INFO VolumeManager: [0x492368]: Setting new playback volume: 75 Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.294 [16154.16154] INFO VolumeManager: [0x492368]: Setting new mute state: 0 Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.294 [16154.16154] INFO QobuzConnect: [0x492d38]: Client initialized! Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.294 [16154.16154] INFO SampleApp: Starting Avahi advertising, name: Volumio_3840x2160, service name: _qobuz-connect._tcp Dec 21 15:12:24 volumio3840x2160 mpd[16153]: 2025-12-21T15:12:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.302 [16154.16154] INFO LocalConfigManager: [0x491c48]: Starting Local Configuration server Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.302 [16154.16154] INFO SampleApp: Starting Local configuration server Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.303 [16154.16154] INFO SampleApp: Connected to UNIX socket client 0x47c818 Dec 21 15:12:24 volumio3840x2160 systemd[1]: Started mpd.service - Music Player Daemon. Dec 21 15:12:24 volumio3840x2160 sudo[16120]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:24 volumio3840x2160 volumio[1366]: error: updateQueue error: null Dec 21 15:12:24 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:24.439 [16154.16154] INFO SampleApp: Playback volume changed: 75 Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:24 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Initializing connection to go-librespot Websocket Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: go-librespot daemon successfully initialized Dec 21 15:12:26 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:26 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:26 volumio3840x2160 sudo[16172]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:26 volumio3840x2160 sudo[16172]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 21 15:12:26 volumio3840x2160 sudo[16172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:26 volumio3840x2160 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 21 15:12:26 volumio3840x2160 sudo[16172]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Executing endpoint tc_getconfig Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 21 15:12:26 volumio3840x2160 vtcs[16175]: STARTING TidalConnect services, version: 1.5.2.56 Dec 21 15:12:26 volumio3840x2160 vtcs[16175]: STARTED TidalConnect services. Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Executing endpoint tc_connect Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Connecting to TidalConnect Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 3 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 21 15:12:26 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:26 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:27 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 21 15:12:27 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:27 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:27 volumio3840x2160 go-librespot[16195]: go-librespot daemon starting... Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="app state loaded" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=info msg="zeroconf server listening on port 32921" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="obtained new client token: AABkx5JDd1mwufy4RTzVve49PG64J3Ni06EBtRMCZJPTz/nIe1BFE7X8r7l2xACSaWuGUkgKF/87Swe2gc/rBolFX7Tlya09uvQJCyB9xPi7MvOjt2JxXDRmPAhMKDTJ0IygYFoRscZPKN3e2KQd+17T+pVeR4b0KVicRTdyBp44KWQ/Jt3Z71+g3p/0XdTA9xtVmj0+otiGzbWLBwnzS6n20Qwvj4y8fVjTUEUifh+2WEQ5QSV/sPSrCA==" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="completed keyexchange" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=debug msg="completed challenge" Dec 21 15:12:27 volumio3840x2160 go-librespot[16196]: time="2025-12-21T15:12:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Dec 21 15:12:27 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:27 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Initializing connection to go-librespot Websocket Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Initializing connection to go-librespot Websocket Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioNext Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::next Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::stop Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::play index undefined Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::startPlaybackTimer Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::clearAddPlayTracks NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B3 Moonlight, Wrapped Around Us.flac Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::updateTrackBlock Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrackBlock Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand stop took 0 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand clear Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Dec 21 15:12:29 volumio3840x2160 volumio[1366]: ---------------------------- MPD announces system playlist update Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Ignoring MPD Status Update Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand clear took 0 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B3 Moonlight, Wrapped Around Us.flac" Dec 21 15:12:29 volumio3840x2160 volumio[1366]: error: updateQueue error: null Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Dec 21 15:12:29 volumio3840x2160 volumio[1366]: ---------------------------- MPD announces system playlist update Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Ignoring MPD Status Update Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ------------------------------ 1ms Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B3 Moonlight, Wrapped Around Us.flac" took 0 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand play Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ------------------------------ 1ms Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand play took 1 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: error: Unable to start TidalConnect service: Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: TidalConnect service started! Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Dec 21 15:12:29 volumio3840x2160 volumio[1366]: ---------------------------- MPD announces state update: player Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ControllerMpd::getState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Dec 21 15:12:29 volumio3840x2160 volumio[1366]: ---------------------------- MPD announces state update: player Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand status took 9 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ControllerMpd::getState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand status took 1 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ControllerMpd::pushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":60,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Moonlight, Wrapped Around Us","artist":"Andreas Vollenweider","album":"... Behind The Gardens - Behind The Wall - Under The Tree ... [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B3 Moonlight, Wrapped Around Us.flac","trackType":"flac"} Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: CURRENT POSITION 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState stateService play Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState currentStatus stop Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ------------------------------ 18ms Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: sendMpdCommand playlistinfo took 6 milliseconds Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ControllerMpd::pushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":60,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Moonlight, Wrapped Around Us","artist":"Andreas Vollenweider","album":"... Behind The Gardens - Behind The Wall - Under The Tree ... [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/Andreas Vollenweider/[1981] ...Behind The Gardens - Behind The Wall - Under The Tree [Vinyl]/B3 Moonlight, Wrapped Around Us.flac","trackType":"flac"} Dec 21 15:12:29 volumio3840x2160 volumio[1366]: verbose: CURRENT POSITION 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState stateService play Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::syncState currentStatus play Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: Received an update from plugin. extracting info from payload Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: info: ------------------------------ 54ms Dec 21 15:12:29 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:29 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:30 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 21 15:12:30 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:30 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:30 volumio3840x2160 go-librespot[16225]: go-librespot daemon starting... Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="app state loaded" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=info msg="zeroconf server listening on port 42213" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="obtained new client token: AADkvncl+vc/qYtTraLADjEMKZdQVHiO4eX1CUN+7LPkwDqUoxa02Kr0GejG0F5eMH2uNmWuwE7sNjvTvEV3uMz6LzKEIaeWDrzTFhMvEG5LhSG4KM56c96WvuDEu27GD+oDnzqxUO90xYzBNi6/6qOi7ucUFBgtxX80sdRVDNT02Ow/RoMnxSLnXzfLmbPEnFcUHTUXBLVlPHVe7uQDoGYRWQCN1Q27KhMWgQ+DCjkEerZOTVwv09vWEQ==" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="completed keyexchange" Dec 21 15:12:30 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:30+01:00" level=debug msg="completed challenge" Dec 21 15:12:31 volumio3840x2160 go-librespot[16226]: time="2025-12-21T15:12:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Dec 21 15:12:31 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:31 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:12:32 volumio3840x2160 volumio[1366]: info: Initializing connection to go-librespot Websocket Dec 21 15:12:32 volumio3840x2160 volumio[1366]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:12:34 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 21 15:12:34 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:34 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:34 volumio3840x2160 go-librespot[16233]: go-librespot daemon starting... Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="app state loaded" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=info msg="zeroconf server listening on port 36713" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="obtained new client token: AABSXittIzHybVFxOT9tblGqBOJM+ngF2iA9CKTmDiOn7hEp623pDiGkkZFcLnp2pBTXb1pMEt9e5oLSMR3VE057xcEAuAa63FtpSSfZXscT3Nak/IvevukNbrJY846HP79odCwidWatKhC3tNCrVBQIZ6Lsn9RICAARsjKtGGWe60NSq15+n+1subvJyTKewpzhcULwKt3WtuaTOQgdRFtsqfMk3FuFlfI/d4xZM1wfs1RzzyTyjs7H3w==" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="completed keyexchange" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=debug msg="completed challenge" Dec 21 15:12:34 volumio3840x2160 go-librespot[16234]: time="2025-12-21T15:12:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Dec 21 15:12:34 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:34 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: Enabling plugin peppy_screensaver Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: Loading plugin "peppy_screensaver"... Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: Applying required configuration parameters for plugin peppy_screensaver Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: Preparing to generate the ALSA configuration file Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: Reading ALSA contributions from plugins. Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: Asound.conf file written Dec 21 15:12:34 volumio3840x2160 sudo[16243]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:34 volumio3840x2160 sudo[16243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 21 15:12:34 volumio3840x2160 sudo[16243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:34 volumio3840x2160 sudo[16243]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:34 volumio3840x2160 volumio[1366]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:34 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 21 15:12:34 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 21 15:12:34 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Dec 21 15:12:34 volumio3840x2160 volumio[1366]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: Output device has changed, restarting MPD Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:34 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:34 volumio3840x2160 vtcs[16175]: [2025-12-21 15:12:34.996] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 21 15:12:34 volumio3840x2160 vtcs[16175]: [2025-12-21 15:12:34.999] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: PLUGIN START: peppy_screensaver Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Loading i18n strings for locale en Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: /tmp/myfifo created Dec 21 15:12:35 volumio3840x2160 sudo[16251]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:12:35 volumio3840x2160 sudo[16251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16249]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: /tmp/myfifosa created Dec 21 15:12:35 volumio3840x2160 sudo[16249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:12:35 volumio3840x2160 sudo[16249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16249]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 21 15:12:35 volumio3840x2160 sudo[16255]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16255]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 21 15:12:35 volumio3840x2160 systemd[1]: vtcs.service: Killing process 16179 (vtcs) with signal SIGKILL. Dec 21 15:12:35 volumio3840x2160 sudo[16264]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 systemd[1]: vtcs.service: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 21 15:12:35 volumio3840x2160 sudo[16264]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Dec 21 15:12:35 volumio3840x2160 sudo[16264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16255]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16264]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 volumio[1366]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: snd-dummy loaded Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:12:35 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Done. Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:35 volumio3840x2160 volumio[1366]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MPD Permissions set Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Creating Spotify config file Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Spotify config file written Dec 21 15:12:35 volumio3840x2160 sudo[16300]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Preparing to generate the ALSA configuration file Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:12:35 volumio3840x2160 sudo[16307]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Reading ALSA contributions from plugins. Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Asound.conf file unchanged, so no further update is needed Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Output device has changed, restarting MPD Dec 21 15:12:35 volumio3840x2160 sudo[16307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 sudo[16288]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16288]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16288]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:12:35 volumio3840x2160 sudo[16288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:12:35 volumio3840x2160 sudo[16300]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16288]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 sudo[16315]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 21 15:12:35 volumio3840x2160 sudo[16315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:35 volumio3840x2160 sudo[16307]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:35 volumio3840x2160 sudo[16315]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16323]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16321]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:12:35 volumio3840x2160 sudo[16321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:12:35 volumio3840x2160 sudo[16323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 go-librespot[16331]: go-librespot daemon starting... Dec 21 15:12:35 volumio3840x2160 sudo[16323]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16327]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16329]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 sudo[16329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 go-librespot[16337]: time="2025-12-21T15:12:35+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:12:35 volumio3840x2160 go-librespot[16337]: time="2025-12-21T15:12:35+01:00" level=debug msg="app state loaded" Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 go-librespot[16337]: time="2025-12-21T15:12:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:12:35 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:12:35 volumio3840x2160 sudo[16332]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 21 15:12:35 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:35.387 [16154.16154] INFO SampleApp: Stopping Local configuration server Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: peppy_screensaver: ALSA template: /data/plugins/user_interface/peppy_screensaver/Peppyalsa.postPeppyalsa.5.conf.tmpl (isX64=false) Dec 21 15:12:35 volumio3840x2160 sudo[16350]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16329]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 sudo[16350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16332]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MPD Permissions set Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Creating Spotify config file Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Preparing to generate the ALSA configuration file Dec 21 15:12:35 volumio3840x2160 sudo[16350]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Reading ALSA contributions from plugins. Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Spotify config file written Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Asound.conf file unchanged, so no further update is needed Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Output device has changed, restarting MPD Dec 21 15:12:35 volumio3840x2160 sudo[16364]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Dec 21 15:12:35 volumio3840x2160 sudo[16364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16364]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16365]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 sudo[16365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16348]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16348]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16348]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:12:35 volumio3840x2160 sudo[16348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:12:35 volumio3840x2160 sudo[16348]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Preparing to generate the ALSA configuration file Dec 21 15:12:35 volumio3840x2160 go-librespot[16337]: time="2025-12-21T15:12:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 21 15:12:35 volumio3840x2160 go-librespot[16337]: time="2025-12-21T15:12:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 21 15:12:35 volumio3840x2160 go-librespot[16337]: time="2025-12-21T15:12:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 21 15:12:35 volumio3840x2160 go-librespot[16337]: time="2025-12-21T15:12:35+01:00" level=info msg="zeroconf server listening on port 35651" Dec 21 15:12:35 volumio3840x2160 sudo[16373]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 21 15:12:35 volumio3840x2160 sudo[16373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16377]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Reading ALSA contributions from plugins. Dec 21 15:12:35 volumio3840x2160 sudo[16377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16380]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile Dec 21 15:12:35 volumio3840x2160 sudo[16380]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:12:35 volumio3840x2160 sudo[16380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16377]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 21 15:12:35 volumio3840x2160 sudo[16385]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:12:35 volumio3840x2160 sudo[16385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16373]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 go-librespot[16397]: go-librespot daemon starting... Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MPD Permissions set Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 sudo[16394]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="app state loaded" Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:12:35 volumio3840x2160 sudo[16394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 sudo[16394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 sudo[16387]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:12:35 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 sudo[16387]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16401]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16385]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:12:35 volumio3840x2160 sudo[16401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16394]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16401]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Initializing connection to go-librespot Websocket Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MPD Permissions set Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Asound.conf file unchanged, so no further update is needed Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Output device has changed, restarting MPD Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="new websocket client" Dec 21 15:12:35 volumio3840x2160 sudo[16387]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16424]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 sudo[16424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 sudo[16424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:35 volumio3840x2160 sudo[16427]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:12:35 volumio3840x2160 sudo[16427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16427]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16429]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:12:35 volumio3840x2160 sudo[16429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=info msg="zeroconf server listening on port 43431" Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Connection to go-librespot Websocket established Dec 21 15:12:35 volumio3840x2160 sudo[16415]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16415]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16436]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: MPD Permissions set Dec 21 15:12:35 volumio3840x2160 sudo[16415]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 sudo[16415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:12:35 volumio3840x2160 sudo[16415]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:12:35 volumio3840x2160 sudo[16439]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:12:35 volumio3840x2160 sudo[16439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 sudo[16445]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 sudo[16445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:12:35 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 sudo[16445]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 sudo[16436]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 sudo[16439]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="obtained new client token: AACUuFPU9Kl384MieHa8iOFnia2h/vwC4Uv7ZJuZqu+ihybx7wJ6bcoqP94gxk7OSAtbtl5ypc9R9YpMikwubP5Ukbk1rNOsXSzXIXTehCEKSczgoZw6z0aJEIGs9TeGl/MHqgYtSG0I0ixwxMl5ySjB3UROY9nat4szIZOS7ZUW+Yx36GVHOHUJEvSWbno29ompopC8eYYiJ3c+cMwD2kI8swVT7F3teIabXw5jYEIR3tzvE3O4Gu+J4A==" Dec 21 15:12:35 volumio3840x2160 sudo[16456]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 21 15:12:35 volumio3840x2160 sudo[16456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:35 volumio3840x2160 sudo[16455]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16455]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 sudo[16455]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:12:35 volumio3840x2160 sudo[16455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:12:35 volumio3840x2160 sudo[16455]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="completed keyexchange" Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=debug msg="completed challenge" Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 go-librespot[16400]: time="2025-12-21T15:12:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:35 volumio3840x2160 volumio[1366]: info: Connection to go-librespot Websocket closed Dec 21 15:12:35 volumio3840x2160 sudo[16463]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:35 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:35 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:12:35 volumio3840x2160 sudo[16463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:12:35 volumio3840x2160 sudo[16463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:36 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:12:36 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Dec 21 15:12:36 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:12:36 volumio3840x2160 sudo[16467]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:36 volumio3840x2160 sudo[16467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:12:36 volumio3840x2160 sudo[16467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:36 volumio3840x2160 sudo[16468]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:12:36 volumio3840x2160 sudo[16468]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:36 volumio3840x2160 sudo[16468]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:12:36 volumio3840x2160 sudo[16468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:12:36 volumio3840x2160 sudo[16468]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:12:36 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:36 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:12:36 volumio3840x2160 sudo[16471]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:12:36 volumio3840x2160 sudo[16471]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:12:36 volumio3840x2160 sudo[16471]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:12:36 volumio3840x2160 sudo[16471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:12:36 volumio3840x2160 sudo[16471]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16154]: 20251221 15:12:36.322 [16154.16154] INFO SampleApp: shat down connection on UNIX socket Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:36 volumio3840x2160 systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:12:36 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:12:36 volumio3840x2160 sudo[16456]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16327]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16365]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16424]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: Executing endpoint qc_getconfig Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.399 [16474.16474] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.401 [16474.16474] INFO VolumeManager: [0xa58368]: Setting new playback volume: 75 Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.401 [16474.16474] INFO VolumeManager: [0xa58368]: Setting new mute state: 0 Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.401 [16474.16474] INFO QobuzConnect: [0xa58d38]: Client initialized! Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.401 [16474.16474] INFO SampleApp: Starting Avahi advertising, name: Volumio_3840x2160, service name: _qobuz-connect._tcp Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.412 [16474.16474] INFO LocalConfigManager: [0xa57c48]: Starting Local Configuration server Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.412 [16474.16474] INFO SampleApp: Starting Local configuration server Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.413 [16474.16474] INFO SampleApp: Connected to UNIX socket client 0xa42818 Dec 21 15:12:36 volumio3840x2160 qobuz-connect[16474]: 20251221 15:12:36.550 [16474.16474] INFO SampleApp: Playback volume changed: 75 Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:36 volumio3840x2160 mpd[16473]: 2025-12-21T15:12:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 21 15:12:36 volumio3840x2160 systemd[1]: Started mpd.service - Music Player Daemon. Dec 21 15:12:36 volumio3840x2160 sudo[16463]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16321]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16467]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16380]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16429]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 sudo[16251]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: MPD error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: MPD error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: MPD error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: MPD error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: MPD error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: The expression evaluated to a falsy value: Dec 21 15:12:36 volumio3840x2160 volumio[1366]: assert.ok(self.idling) Dec 21 15:12:36 volumio3840x2160 volumio[1366]: error: updateQueue error: null Dec 21 15:12:36 volumio3840x2160 volumio[1366]: info: peppy_screensaver: MPD output 1 enabled Dec 21 15:12:38 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: peppy_screensaver: Startup - MPD output 1 enabled Dec 21 15:12:38 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:38 volumio3840x2160 sudo[16499]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:38 volumio3840x2160 sudo[16499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 21 15:12:38 volumio3840x2160 sudo[16499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:38 volumio3840x2160 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 21 15:12:38 volumio3840x2160 sudo[16499]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:38 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:38 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: go-librespot daemon successfully initialized Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Executing endpoint tc_getconfig Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 21 15:12:38 volumio3840x2160 vtcs[16502]: STARTING TidalConnect services, version: 1.5.2.56 Dec 21 15:12:38 volumio3840x2160 vtcs[16502]: STARTED TidalConnect services. Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Executing endpoint tc_connect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Connecting to TidalConnect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::servicePushState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreStateMachine::pushState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioPushState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CoreCommandRouter::volumioGetState Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: CorePlayQueue::getTrack 4 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:38 volumio3840x2160 sudo[16527]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:38 volumio3840x2160 sudo[16527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 21 15:12:38 volumio3840x2160 sudo[16527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:38 volumio3840x2160 sudo[16527]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: go-librespot daemon successfully initialized Dec 21 15:12:38 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:38 volumio3840x2160 volumio[1366]: error: Unable to stop TidalConnect service: Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: TidalConnect service stoped! Dec 21 15:12:38 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 484. Dec 21 15:12:38 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:12:38 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:12:38 volumio3840x2160 upmpdcli[16535]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:12:38 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:12:38 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:12:38 volumio3840x2160 sudo[16544]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:38 volumio3840x2160 sudo[16544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 21 15:12:38 volumio3840x2160 sudo[16544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:12:38 volumio3840x2160 sudo[16544]: pam_unix(sudo:session): session closed for user root Dec 21 15:12:38 volumio3840x2160 volumio[1366]: info: Getting Spotify volume Dec 21 15:12:38 volumio3840x2160 volumio[1366]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 15:12:38 volumio3840x2160 volumio[1366]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:12:38 volumio3840x2160 volumio[1366]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 21 15:12:38 volumio3840x2160 volumio[1366]: errno: -111, Dec 21 15:12:38 volumio3840x2160 volumio[1366]: code: 'ECONNREFUSED', Dec 21 15:12:38 volumio3840x2160 volumio[1366]: syscall: 'connect', Dec 21 15:12:38 volumio3840x2160 volumio[1366]: address: '127.0.0.1', Dec 21 15:12:38 volumio3840x2160 volumio[1366]: port: 9879, Dec 21 15:12:38 volumio3840x2160 volumio[1366]: response: undefined Dec 21 15:12:38 volumio3840x2160 volumio[1366]: } Dec 21 15:12:38 volumio3840x2160 volumio[1366]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 15:12:38 volumio3840x2160 sudo[16561]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:12:38 volumio3840x2160 sudo[16561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-21 15:11' Dec 21 15:12:38 volumio3840x2160 sudo[16561]: 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="5250573efb99f2852fa27ea7e92def8586093039" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="d9e2b6784b9276d5a676bf564ce7524ad160509b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 19 15:53:15 UTC 2025" VOLUMIO_VERSION="4.082" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="47d7740e8c55792fe06a847eb7ad6b29"