Dec 21 15:31:14 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 29. Dec 21 15:31:14 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:31:14 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:31:14 volumio3840x2160 upmpdcli[7946]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:31:14 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:31:14 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:31:29 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 30. Dec 21 15:31:29 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:31:29 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:31:29 volumio3840x2160 upmpdcli[7976]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:31:29 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:31:29 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:31:31 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 21 15:31:31 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 21 15:31:36 volumio3840x2160 sudo[7994]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:31:36 volumio3840x2160 sudo[7994]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sed -i s/localhost:4004/localhost:3000/g /opt/volumiokiosk.sh Dec 21 15:31:36 volumio3840x2160 sudo[7994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:31:36 volumio3840x2160 sudo[7994]: pam_unix(sudo:session): session closed for user root Dec 21 15:31:36 volumio3840x2160 volumio[7085]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:31:36 volumio3840x2160 volumio[7085]: [sudo] password for volumio: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl status volumio-kiosk Dec 21 15:31:36 volumio3840x2160 sudo[7997]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:31:36 volumio3840x2160 sudo[7997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status volumio-kiosk Dec 21 15:31:36 volumio3840x2160 sudo[7997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:31:36 volumio3840x2160 sudo[7997]: pam_unix(sudo:session): session closed for user root Dec 21 15:31:36 volumio3840x2160 volumio[7085]: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl restart volumio-kiosk Dec 21 15:31:36 volumio3840x2160 sudo[8000]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:31:36 volumio3840x2160 sudo[8000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk Dec 21 15:31:36 volumio3840x2160 sudo[8000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:31:36 volumio3840x2160 systemd[1]: Stopping volumio-kiosk.service - Volumio Kiosk... Dec 21 15:31:36 volumio3840x2160 startx[1841]: xinit: connection to X server lost Dec 21 15:31:36 volumio3840x2160 startx[1841]: Dec 21 15:31:36 volumio3840x2160 startx[1841]: waiting for X server to shut down Dec 21 15:31:36 volumio3840x2160 startx[1842]: (II) Server terminated successfully (0). Closing log file. Dec 21 15:31:37 volumio3840x2160 startx[1841]: xinit: unexpected signal 15 Dec 21 15:31:37 volumio3840x2160 startx[8006]: xauth: (argv):1: bad display name "volumio3840x2160:0" in "remove" command Dec 21 15:31:37 volumio3840x2160 systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:31:37 volumio3840x2160 systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Dec 21 15:31:37 volumio3840x2160 systemd[1]: Stopped volumio-kiosk.service - Volumio Kiosk. Dec 21 15:31:37 volumio3840x2160 systemd[1]: volumio-kiosk.service: Consumed 1min 8.106s CPU time. Dec 21 15:31:37 volumio3840x2160 systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Dec 21 15:31:37 volumio3840x2160 sudo[8000]: pam_unix(sudo:session): session closed for user root Dec 21 15:31:37 volumio3840x2160 volumio[7085]: warn: [now-playing] MyBackgroundMonitor stopped Dec 21 15:31:37 volumio3840x2160 volumio[7085]: info: Disabling plugin now_playing Dec 21 15:31:37 volumio3840x2160 volumio[7085]: info: Done. Dec 21 15:31:37 volumio3840x2160 startx[8017]: hostname: System error Dec 21 15:31:37 volumio3840x2160 startx[8029]: xauth: (stdin):1: bad display name "volumio3840x2160:0" in "add" command Dec 21 15:31:37 volumio3840x2160 startx[8031]: X.Org X Server 1.21.1.7 Dec 21 15:31:37 volumio3840x2160 startx[8031]: X Protocol Version 11, Revision 0 Dec 21 15:31:37 volumio3840x2160 startx[8031]: Current Operating System: Linux volumio3840x2160 6.12.47-v8+ #1904 SMP PREEMPT Mon Sep 15 13:10:52 BST 2025 aarch64 Dec 21 15:31:37 volumio3840x2160 startx[8031]: Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe cgroup_disable=memory numa_policy=interleave nvme.max_host_mem_size_mb=0 numa=fake=8 system_heap.max_order=0 iommu_dma_numa_policy=interleave smsc95xx.macaddr=2C:CF:67:47:EF:DE vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA10,115200 console=tty1 imgpart=UUID=f8226a5a-f748-437b-add3-2c885465558c imgfile=/volumio_current.sqsh bootpart=UUID=357E-424A datapart=UUID=af262b4f-8b6f-4e16-8511-f06e120bc670 uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Dec 21 15:31:37 volumio3840x2160 startx[8031]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Dec 21 15:31:37 volumio3840x2160 startx[8031]: Current version of pixman: 0.44.0 Dec 21 15:31:37 volumio3840x2160 startx[8031]: Before reporting problems, check http://wiki.x.org Dec 21 15:31:37 volumio3840x2160 startx[8031]: to make sure that you have the latest version. Dec 21 15:31:37 volumio3840x2160 startx[8031]: Markers: (--) probed, (**) from config file, (==) default setting, Dec 21 15:31:37 volumio3840x2160 startx[8031]: (++) from command line, (!!) notice, (II) informational, Dec 21 15:31:37 volumio3840x2160 startx[8031]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Dec 21 15:31:37 volumio3840x2160 startx[8031]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Dec 21 15:31:37 2025 Dec 21 15:31:37 volumio3840x2160 startx[8031]: (==) Using config directory: "/etc/X11/xorg.conf.d" Dec 21 15:31:37 volumio3840x2160 startx[8031]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Dec 21 15:31:40 volumio3840x2160 volumio[7085]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Dec 21 15:31:41 volumio3840x2160 volumio[7085]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetVisibleSources Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: Received Get System Info Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: Discovery: Getting this device information Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: Listing playlists Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 21 15:31:41 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 21 15:31:43 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:43 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: Received Get System Info Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: Discovery: Getting this device information Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 21 15:31:44 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 21 15:31:45 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 31. Dec 21 15:31:45 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:31:45 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:31:45 volumio3840x2160 upmpdcli[8205]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:31:45 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:31:45 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:31:45 volumio3840x2160 volumio[7085]: info: Executing endpoint metavolumio Dec 21 15:31:45 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 21 15:31:45 volumio3840x2160 volumio[7085]: info: Executing endpoint metavolumio Dec 21 15:31:45 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 21 15:31:45 volumio3840x2160 volumio[7085]: info: Executing endpoint metavolumio Dec 21 15:31:45 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: Received Get System Info Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: Discovery: Getting this device information Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: Received Get System Info Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: Discovery: Getting this device information Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:46 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:31:51 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioNext Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::next Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::stop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::stPlaybackTimer Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::updateTrackBlock Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrackBlock Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioPushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::serviceStop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 2 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::serviceStop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ControllerMpd::stop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Dec 21 15:31:52 volumio3840x2160 volumio[7085]: ---------------------------- MPD announces state update: player Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand stop took 14 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ControllerMpd::getState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::play index undefined Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::startPlaybackTimer Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::clearAddPlayTracks NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A4 Smooth Criminal.flac Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::updateTrackBlock Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrackBlock Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand status took 1 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::parseState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand stop took 6 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand playlistinfo took 6 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand clear Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ControllerMpd::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::servicePushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioPushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: 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":"Use Somebody","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A3 Use Somebody.flac","trackType":"flac"} Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: CURRENT POSITION 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::syncState stateService stop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::syncState currentStatus stop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioPushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: No code Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioPushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ------------------------------ 31ms Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Dec 21 15:31:52 volumio3840x2160 volumio[7085]: ---------------------------- MPD announces system playlist update Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Ignoring MPD Status Update Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand clear took 24 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A4 Smooth Criminal.flac" Dec 21 15:31:52 volumio3840x2160 volumio[7085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 21 15:31:52 volumio3840x2160 volumio[7085]: error: updateQueue error: null Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Dec 21 15:31:52 volumio3840x2160 volumio[7085]: ---------------------------- MPD announces system playlist update Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Ignoring MPD Status Update Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ------------------------------ 14ms Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A4 Smooth Criminal.flac" took 14 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand play Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ------------------------------ 5ms Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand play took 4 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Dec 21 15:31:52 volumio3840x2160 volumio[7085]: ---------------------------- MPD announces state update: player Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ControllerMpd::getState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Dec 21 15:31:52 volumio3840x2160 volumio[7085]: ---------------------------- MPD announces state update: player Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ControllerMpd::getState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand status took 2 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::parseState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand status took 4 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::parseState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ControllerMpd::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::servicePushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Smooth Criminal","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A4 Smooth Criminal.flac","trackType":"flac"} Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: CURRENT POSITION 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::syncState stateService play Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::syncState currentStatus stop Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ------------------------------ 8ms Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ControllerMpd::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::servicePushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Smooth Criminal","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A4 Smooth Criminal.flac","trackType":"flac"} Dec 21 15:31:52 volumio3840x2160 volumio[7085]: verbose: CURRENT POSITION 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::syncState stateService play Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::syncState currentStatus play Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: Received an update from plugin. extracting info from payload Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioPushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreStateMachine::pushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioPushState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: info: ------------------------------ 26ms Dec 21 15:31:52 volumio3840x2160 volumio[7085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:31:52 volumio3840x2160 volumio[7085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: Received Get System Version Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: Received Get System Info Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: Discovery: Getting this device information Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:31:59 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:32:00 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 32. Dec 21 15:32:00 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:32:00 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:32:00 volumio3840x2160 upmpdcli[8237]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:32:00 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:00 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Enabling plugin peppy_screensaver Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Loading plugin "peppy_screensaver"... Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Applying required configuration parameters for plugin peppy_screensaver Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Preparing to generate the ALSA configuration file Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Reading ALSA contributions from plugins. Dec 21 15:32:03 volumio3840x2160 volumio[7085]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Asound.conf file written Dec 21 15:32:03 volumio3840x2160 sudo[8240]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 21 15:32:03 volumio3840x2160 sudo[8240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 sudo[8240]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 volumio[7085]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 volumio[7085]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 21 15:32:03 volumio3840x2160 volumio[7085]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 21 15:32:03 volumio3840x2160 volumio[7085]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Dec 21 15:32:03 volumio3840x2160 volumio[7085]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Output device has changed, restarting MPD Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:32:03 volumio3840x2160 vtcs[7554]: [2025-12-21 15:32:03.662] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 21 15:32:03 volumio3840x2160 vtcs[7554]: [2025-12-21 15:32:03.665] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 21 15:32:03 volumio3840x2160 sudo[8246]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:32:03 volumio3840x2160 sudo[8246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: PLUGIN START: peppy_screensaver Dec 21 15:32:03 volumio3840x2160 sudo[8246]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Loading i18n strings for locale en Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: /tmp/myfifo created Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: /tmp/myfifosa created Dec 21 15:32:03 volumio3840x2160 sudo[8248]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:32:03 volumio3840x2160 sudo[8248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 sudo[8253]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8253]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:32:03 volumio3840x2160 sudo[8253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 21 15:32:03 volumio3840x2160 systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 21 15:32:03 volumio3840x2160 sudo[8260]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8260]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Dec 21 15:32:03 volumio3840x2160 systemd[1]: vtcs.service: Deactivated successfully. Dec 21 15:32:03 volumio3840x2160 systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 21 15:32:03 volumio3840x2160 sudo[8260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 sudo[8260]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 sudo[8253]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 volumio[7085]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: snd-dummy loaded Dec 21 15:32:03 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:32:03 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:32:03 volumio3840x2160 systemd[1]: mpd.service: Consumed 2.601s CPU time. Dec 21 15:32:03 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:32:03 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:32:03 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:32:03 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Done. Dec 21 15:32:03 volumio3840x2160 volumio[7085]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: MPD Permissions set Dec 21 15:32:03 volumio3840x2160 sudo[8295]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Creating Spotify config file Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 sudo[8295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:32:03 volumio3840x2160 sudo[8295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 sudo[8301]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 21 15:32:03 volumio3840x2160 sudo[8301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Spotify config file written Dec 21 15:32:03 volumio3840x2160 sudo[8288]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8288]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8288]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:32:03 volumio3840x2160 sudo[8301]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 sudo[8288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:32:03 volumio3840x2160 sudo[8288]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 sudo[8295]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Preparing to generate the ALSA configuration file Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Reading ALSA contributions from plugins. Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Asound.conf file unchanged, so no further update is needed Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: Output device has changed, restarting MPD Dec 21 15:32:03 volumio3840x2160 sudo[8311]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 21 15:32:03 volumio3840x2160 sudo[8312]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:03 volumio3840x2160 sudo[8311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 sudo[8312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 21 15:32:03 volumio3840x2160 sudo[8312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: QobuzConnect: setDeactiveState invoked Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:03 volumio3840x2160 volumio[7085]: info: CorePlayQueue::getTrack 3 Dec 21 15:32:03 volumio3840x2160 sudo[8316]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 sudo[8316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:32:03 volumio3840x2160 sudo[8316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:03 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:03 volumio3840x2160 sudo[8316]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:03 volumio3840x2160 sudo[8318]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:03 volumio3840x2160 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 21 15:32:04 volumio3840x2160 sudo[8311]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 21 15:32:04 volumio3840x2160 sudo[8318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:32:04 volumio3840x2160 sudo[8318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:04 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:04 volumio3840x2160 sudo[8324]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 sudo[8324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:32:04 volumio3840x2160 sudo[8324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:04 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:04 volumio3840x2160 go-librespot[8338]: go-librespot daemon starting... Dec 21 15:32:04 volumio3840x2160 sudo[8312]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 sudo[8327]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=debug msg="app state loaded" Dec 21 15:32:04 volumio3840x2160 volumio[7085]: info: peppy_screensaver: ALSA template: /data/plugins/user_interface/peppy_screensaver/Peppyalsa.postPeppyalsa.5.conf.tmpl (isX64=false) Dec 21 15:32:04 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:04 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:32:04 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:32:04 volumio3840x2160 sudo[8327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:32:04 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:32:04 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:32:04 volumio3840x2160 sudo[8327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:04 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:32:04 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:32:04 volumio3840x2160 sudo[8335]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 sudo[8335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 21 15:32:04 volumio3840x2160 sudo[8335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:04 volumio3840x2160 volumio[7085]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 21 15:32:04 volumio3840x2160 volumio[7085]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 15:32:04 volumio3840x2160 volumio[7085]: Error: socket hang up Dec 21 15:32:04 volumio3840x2160 volumio[7085]: at connResetException (node:internal/errors:720:14) Dec 21 15:32:04 volumio3840x2160 volumio[7085]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 21 15:32:04 volumio3840x2160 volumio[7085]: at Socket.emit (node:events:526:35) Dec 21 15:32:04 volumio3840x2160 volumio[7085]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 21 15:32:04 volumio3840x2160 volumio[7085]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 21 15:32:04 volumio3840x2160 volumio[7085]: code: 'ECONNRESET', Dec 21 15:32:04 volumio3840x2160 volumio[7085]: response: undefined Dec 21 15:32:04 volumio3840x2160 volumio[7085]: } Dec 21 15:32:04 volumio3840x2160 volumio[7085]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 15:32:04 volumio3840x2160 sudo[8357]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 sudo[8324]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 sudo[8335]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 sudo[8357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Dec 21 15:32:04 volumio3840x2160 sudo[8357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:04 volumio3840x2160 sudo[8357]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 sudo[8327]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 sudo[8352]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 sudo[8352]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 sudo[8352]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:32:04 volumio3840x2160 sudo[8352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:32:04 volumio3840x2160 sudo[8352]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 sudo[8369]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 sudo[8369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 21 15:32:04 volumio3840x2160 sudo[8369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:04 volumio3840x2160 systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 21 15:32:04 volumio3840x2160 systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 21 15:32:04 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+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:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+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:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+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:32:04 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:04 volumio3840x2160 sudo[8369]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=info msg="zeroconf server listening on port 44473" Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=debug msg="obtained new client token: AAC068S1cRPkjScZ+z5zNZKeXa/B2758hQsBTIAvDS6SD2xWUJhQydl4xkeGyGJ6HILs3zESpB0AZnvwms/w1219Itvk7qhA13l+ZrXQ256tw5lsGXy6Ab2Lf/bR8fylecBoYW2SPabsIprYT+sbQw+eF5G8rwdVKabXdcUh0gd8ed110gmwx7RAkm+zGaDRCFxHZDe1P8RhK53cbCPkuaT2xpvs1MD+wZ1TlhfuekM136BuA9hTIZQ+Uw==" Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:04 volumio3840x2160 sudo[8382]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+01:00" level=debug msg="completed challenge" Dec 21 15:32:04 volumio3840x2160 sudo[8382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-21 15:31' Dec 21 15:32:04 volumio3840x2160 sudo[8382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:04 volumio3840x2160 sudo[8382]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 go-librespot[8343]: time="2025-12-21T15:32:04+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:32:04 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:04 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:04 volumio3840x2160 volumio[7085]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:04 volumio3840x2160 volumio-remote-updater[980]: [2025-12-21 15:32:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 21 15:32:04 volumio3840x2160 volumio-remote-updater[980]: [2025-12-21 15:32:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: Error: Application ID was not specified! Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -n|--deviceName: Device name Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -l|--model: Device's model name Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -s|--serialNumber: Device's serial number Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:04 volumio3840x2160 qobuz-connect[8379]: -h|--help: Print this help Dec 21 15:32:04 volumio3840x2160 mpd[8377]: 2025-12-21T15:32:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 21 15:32:04 volumio3840x2160 sudo[8248]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:04 volumio3840x2160 sudo[8318]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:04 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:04 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:04 volumio3840x2160 systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 21 15:32:04 volumio3840x2160 systemd[1]: volumio.service: Consumed 23.648s CPU time. Dec 21 15:32:04 volumio3840x2160 systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 21 15:32:04 volumio3840x2160 systemd[1]: dynamicswap.service: Deactivated successfully. Dec 21 15:32:04 volumio3840x2160 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9. Dec 21 15:32:04 volumio3840x2160 systemd[1]: Started mpd.service - Music Player Daemon. Dec 21 15:32:05 volumio3840x2160 systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 21 15:32:05 volumio3840x2160 systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 21 15:32:05 volumio3840x2160 systemd[1]: volumio.service: Consumed 23.648s CPU time. Dec 21 15:32:05 volumio3840x2160 systemd[1]: Started volumio.service - Volumio Backend Module. Dec 21 15:32:05 volumio3840x2160 systemd[1]: dynamicswap.service: Deactivated successfully. Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ------------------------------------------- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ----- Volumio3 ---- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ------------------------------------------- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ----- System startup ---- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ------------------------------------------- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: MYVOLUMIO Environment detected Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Plugin folders cleanup Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning into folder /volumio/app/plugins/ Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category audio_interface Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category miscellanea Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category music_service Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category plugins.json Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category system_controller Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category user_interface Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning into folder /data/plugins/ Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category music_service Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category system_controller Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Scanning category user_interface Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Plugin folders cleanup completed Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ------------------------------------------- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ----- Core plugins startup ---- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: ------------------------------------------- Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Loading plugins from folder /volumio/app/plugins/ Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Adding plugin upnp to MyMusic Plugins Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Loading plugins from folder /data/plugins/ Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Loading plugin "system"... Dec 21 15:32:05 volumio3840x2160 volumio[8411]: info: Loading plugin "appearance"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "network"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Refreshing Cached IP Addresses Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "services"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "alsa_controller"... Dec 21 15:32:06 volumio3840x2160 sudo[8439]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "wizard"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "networkfs"... Dec 21 15:32:06 volumio3840x2160 sudo[8441]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:06 volumio3840x2160 sudo[8439]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 21 15:32:06 volumio3840x2160 sudo[8441]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 21 15:32:06 volumio3840x2160 sudo[8441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:06 volumio3840x2160 sudo[8441]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:06 volumio3840x2160 sudo[8439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:06 volumio3840x2160 sudo[8439]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:06 volumio3840x2160 sudo[8448]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Cannot mount NAS Music_GP at system boot, trial number 1 ,retrying in 5 seconds Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Starting Udev Watcher for removable devices Dec 21 15:32:06 volumio3840x2160 sudo[8448]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 21 15:32:06 volumio3840x2160 sudo[8448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Ignoring mount for partition: boot Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Ignoring mount for partition: volumio Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Ignoring mount for partition: volumio_data Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "volumio_command_line_client"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Plugin upnp is not enabled Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "my_music"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "mpd"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Plugin upnp_browser is not enabled Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "alarm-clock"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Plugin airplay_emulation is not enabled Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "last_100"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "webradio"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "i2s_dacs"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "volumiodiscovery"... Dec 21 15:32:06 volumio3840x2160 volumio[8411]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 21 15:32:06 volumio3840x2160 volumio[8411]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 21 15:32:06 volumio3840x2160 volumio[8411]: *** WARNING *** For more information see Dec 21 15:32:06 volumio3840x2160 volumio[8411]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 21 15:32:06 volumio3840x2160 volumio[8411]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 21 15:32:06 volumio3840x2160 volumio[8411]: *** WARNING *** For more information see Dec 21 15:32:06 volumio3840x2160 node[8411]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 21 15:32:06 volumio3840x2160 node[8411]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 21 15:32:06 volumio3840x2160 node[8411]: *** WARNING *** For more information see Dec 21 15:32:06 volumio3840x2160 node[8411]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 21 15:32:06 volumio3840x2160 node[8411]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 21 15:32:06 volumio3840x2160 node[8411]: *** WARNING *** For more information see Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Discovery: Started advertising with name: Volumio_3840x2160 Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 21 15:32:06 volumio3840x2160 volumio[8411]: info: Loading plugin "spop"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Plugin now_playing is not enabled Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Plugin peppy_screensaver is not enabled Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "outputs"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "albumart"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Plugin example_plugin is not enabled Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "inputs"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "updater_comm"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Plugin mpdemulation is not enabled Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "rest_api"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "websocket"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Starting Socket.io Server version 1.7.4 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "rpi_eeprom_updater"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Applying required configuration parameters for plugin rpi_eeprom_updater Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "Systeminfo"... Dec 21 15:32:07 volumio3840x2160 volumio[8471]: Forking 3 albumart workers Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading plugin "touch_display"... Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Applying required configuration parameters for plugin touch_display Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Loading i18n strings for locale en Dec 21 15:32:07 volumio3840x2160 volumio[8411]: Updating browse sources language Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:07 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 21 15:32:07 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::initPlayerControls Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: Express server listening on port 3000 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: [Metrics] WebUI: 2s 118.84ms Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::resetVolumioState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::getcurrentVolume Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioRetrievevolume Dec 21 15:32:07 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:07 volumio3840x2160 go-librespot[8511]: go-librespot daemon starting... Dec 21 15:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+01:00" level=debug msg="app state loaded" Dec 21 15:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Volumio Network Manager: Network status updated: 1 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::updateTrackBlock Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrackBlock Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioRetrievevolume Dec 21 15:32:07 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.128 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/140.0.0.0 Safari/537.36 OPR/124.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Reloading queue from file Dec 21 15:32:07 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.24 UA: Mozilla/5.0 (Linux; Android 16; CPH2581 Build/BP2A.250605.015; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::setRepeat null single undefined Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::setRandom null Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Setting Device type: Raspberry PI Dec 21 15:32:07 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 192.168.1.97:3000 from 192.168.1.24 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 4 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04170 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 21 15:32:07 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.128 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/140.0.0.0 Safari/537.36 OPR/124.0.0.0 Engine version: 3 Transport: polling Total Clients: 5 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Completed loading Core Plugins Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Preparing to generate the ALSA configuration file Dec 21 15:32:07 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 21 15:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+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:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+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:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+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:32:07 volumio3840x2160 volumio[8411]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Reading ALSA contributions from plugins. Dec 21 15:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+01:00" level=info msg="zeroconf server listening on port 42141" Dec 21 15:32:07 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 21 15:32:07 volumio3840x2160 volumio[8482]: Starting albumart workers Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Discovery: Getting this device information Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:32:07 volumio3840x2160 volumio[8481]: Starting albumart workers Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 21 15:32:07 volumio3840x2160 volumio[8483]: Starting albumart workers Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Discovery: adding 7d7396b9-8aeb-472a-9bf4-4627ea7d6f66 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Discovery: Found device Volumio_3840x2160 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+01:00" level=debug msg="obtained new client token: AAAX7Y4FF1/sYw+f/19/cEV0ch3BGTQhOOSW02lzsL4fgRkad2Myt47Zi/hKY5QTSyAdYjnL63try8HBFwOFI7DYz7+kT5lZ5LsrLko/aLZxzjehziceA1Ysssyb+sKshIiF5L3+DfmwjtFLXaHU3nl+6egUNtbZU9R6g8iCndyumCyg6sBywTBiN3+XYJFnvtv9Z4GgybkHbRbwkUuF1Gkm5T4o64maL0yEXXj0UNJfLA8X30AlyERMHg==" Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Discovery: this is already registered, 7d7396b9-8aeb-472a-9bf4-4627ea7d6f66 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Discovery: Found device Volumio_3840x2160 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Discovery: Getting this device information Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetVisibleSources Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Received Get System Info Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Discovery: Getting this device information Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:32:07 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: Listing playlists Dec 21 15:32:07 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 21 15:32:08 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:08+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:08 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:08+01:00" level=debug msg="completed challenge" Dec 21 15:32:08 volumio3840x2160 go-librespot[8523]: time="2025-12-21T15:32:08+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:32:08 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 192.168.1.97:3000 from 192.168.1.24 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 21 15:32:08 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:08 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetVisibleSources Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Received Get System Info Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Discovery: Getting this device information Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Listing playlists Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Asound.conf file written Dec 21 15:32:08 volumio3840x2160 sudo[8557]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 21 15:32:08 volumio3840x2160 sudo[8557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8557]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 volumio[8411]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 volumio[8411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Output device has changed, restarting MPD Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: ___________ START PLUGINS ___________ Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: ControllerMpd::onStart: Initializing MPD Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Creating MPD Configuration file Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: [1766327528324] CoreMusicLibrary::Adding element Last_100 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: [1766327528327] CoreMusicLibrary::Adding element Webradio Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Initializing BBC Radios Dec 21 15:32:08 volumio3840x2160 sudo[8569]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:32:08 volumio3840x2160 sudo[8569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8569]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 sudo[8571]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:08 volumio3840x2160 sudo[8573]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:32:08 volumio3840x2160 sudo[8571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Creating Spotify config file Dec 21 15:32:08 volumio3840x2160 sudo[8573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 sudo[8575]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:32:08 volumio3840x2160 sudo[8575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8573]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 21 15:32:08 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:32:08 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:32:08 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:32:08 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:32:08 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:32:08 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:32:08 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: [RpiEepromUpdater] Plugin started successfully Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Loading i18n strings for locale en Dec 21 15:32:08 volumio3840x2160 sudo[8594]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Volumio Calling Home Dec 21 15:32:08 volumio3840x2160 sudo[8594]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8594]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:32:08 volumio3840x2160 sudo[8594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:32:08 volumio3840x2160 sudo[8594]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 sudo[8617]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8617]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Dec 21 15:32:08 volumio3840x2160 sudo[8617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8617]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 sudo[8624]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Dec 21 15:32:08 volumio3840x2160 sudo[8624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8626]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8628]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 21 15:32:08 volumio3840x2160 sudo[8628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Dec 21 15:32:08 volumio3840x2160 sudo[8626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 systemd[1]: Reloading. Dec 21 15:32:08 volumio3840x2160 sudo[8448]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.128 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/140.0.0.0 Safari/537.36 OPR/124.0.0.0 Engine version: 3 Transport: polling Total Clients: 8 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: touch_display: No backlight interface detected. Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: MPD Permissions set Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: MPD Permissions set Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Spotify config file written Dec 21 15:32:08 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Volumio called home Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 sudo[8635]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8635]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Dec 21 15:32:08 volumio3840x2160 sudo[8635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 sudo[8635]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: No need to fix Spotify hosts Dec 21 15:32:08 volumio3840x2160 sudo[8637]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 21 15:32:08 volumio3840x2160 sudo[8637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: touch_display: IframeKeyboardBridge extension installed successfully Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 sudo[8668]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Dec 21 15:32:08 volumio3840x2160 sudo[8668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.24 UA: Mozilla/5.0 (Linux; Android 16; CPH2581 Build/BP2A.250605.015; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Dec 21 15:32:08 volumio3840x2160 sudo[8670]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:08 volumio3840x2160 sudo[8670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Dec 21 15:32:08 volumio3840x2160 sudo[8670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:08 volumio3840x2160 sudo[8668]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Dec 21 15:32:08 volumio3840x2160 sudo[8670]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Dec 21 15:32:08 volumio3840x2160 volumio[8411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 21 15:32:08 volumio3840x2160 volumio[8411]: SPOTIFY: BQD5MboBBdGs9nS7hQHkqHKM5wllSgBl_bR_S-2WCkmoqIEerJNLiYswW99ZV1j9Y56XgoDySC8xBaXye13dhuic2AHmT3B_mSrKLWNRR28TK0J-NDSIGSOJNyITh_G0D38LTIDuqWiXVq4oPv98GyEe9zVcvTmznAXwYClswcpTwD90k9z5jbuaxiDbsdxNC0EyqEMtc6AGgYgR3PiihPc_NZp3kBQuwHPhWlzonW7GQ1bQw4z8C2fl9fboKLMAuEeTGzipvk-tfcEOtl4AN_FITzAvje4RHHU9r1Ps-fF9TF0mgYB1qUhM Dec 21 15:32:08 volumio3840x2160 volumio[8411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: New Spotify access token = BQD5MboBBdGs9nS7hQHkqHKM5wllSgBl_bR_S-2WCkmoqIEerJNLiYswW99ZV1j9Y56XgoDySC8xBaXye13dhuic2AHmT3B_mSrKLWNRR28TK0J-NDSIGSOJNyITh_G0D38LTIDuqWiXVq4oPv98GyEe9zVcvTmznAXwYClswcpTwD90k9z5jbuaxiDbsdxNC0EyqEMtc6AGgYgR3PiihPc_NZp3kBQuwHPhWlzonW7GQ1bQw4z8C2fl9fboKLMAuEeTGzipvk-tfcEOtl4AN_FITzAvje4RHHU9r1Ps-fF9TF0mgYB1qUhM Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetVisibleSources Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Received Get System Info Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Discovery: Getting this device information Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:08 volumio3840x2160 volumio[8411]: info: Listing playlists Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetVisibleSources Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetQueue Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreStateMachine::getQueue Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getQueue Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: Listing playlists Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: Received Get System Info Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: Discovery: Getting this device information Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:09 volumio3840x2160 volumio[8411]: SPOTIFY: User informations: {"country":"NG","display_name":"Lowerymichael","email":"lowerymichael1332@outlook.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31rpeznnia6zthzdlzxkalygovbe"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31rpeznnia6zthzdlzxkalygovbe","id":"31rpeznnia6zthzdlzxkalygovbe","images":[],"product":"free","type":"user","uri":"spotify:user:31rpeznnia6zthzdlzxkalygovbe"} Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: Spotify Successfully logged in Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: [1766327529190] CoreMusicLibrary::Adding element Spotify Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:09 volumio3840x2160 volumio[8411]: Cannot find translation for source Spotify Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 sudo[8628]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: touch_display: systemctl daemon-reload succeeded. Dec 21 15:32:09 volumio3840x2160 mpd[8621]: 2025-12-21T15:32:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 21 15:32:09 volumio3840x2160 sudo[8624]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: touch_display: systemctl stop getty@tty1.service succeeded. Dec 21 15:32:09 volumio3840x2160 systemd[1]: Reloading. Dec 21 15:32:09 volumio3840x2160 sudo[8675]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:09 volumio3840x2160 sudo[8675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Dec 21 15:32:09 volumio3840x2160 sudo[8675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:09 volumio3840x2160 volumio-remote-updater[980]: [2025-12-21 15:32:09] [connect] Successful connection Dec 21 15:32:09 volumio3840x2160 volumio-remote-updater[980]: [2025-12-21 15:32:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1766327529 101 Dec 21 15:32:09 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 11 Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 21 15:32:09 volumio3840x2160 systemd[1]: Started mpd.service - Music Player Daemon. Dec 21 15:32:09 volumio3840x2160 sudo[8571]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:09 volumio3840x2160 sudo[8626]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:09 volumio3840x2160 systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 1. Dec 21 15:32:09 volumio3840x2160 sudo[8575]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:09 volumio3840x2160 volumio[8411]: info: touch_display: systemctl disable getty@tty1.service succeeded. Dec 21 15:32:09 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:10 volumio3840x2160 volumio[8411]: error: MPD error: The expression evaluated to a falsy value: Dec 21 15:32:10 volumio3840x2160 volumio[8411]: assert.ok(self.idling) Dec 21 15:32:10 volumio3840x2160 volumio[8411]: error: The expression evaluated to a falsy value: Dec 21 15:32:10 volumio3840x2160 volumio[8411]: assert.ok(self.idling) Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: MPD running with PID8621 Dec 21 15:32:10 volumio3840x2160 volumio[8411]: ,establishing connection Dec 21 15:32:10 volumio3840x2160 volumio[8411]: error: updateQueue error: null Dec 21 15:32:10 volumio3840x2160 volumio[8411]: error: updateQueue error: null Dec 21 15:32:10 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:10 volumio3840x2160 go-librespot[8698]: go-librespot daemon starting... Dec 21 15:32:10 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:10 volumio3840x2160 sudo[8637]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:10 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:10 volumio3840x2160 sudo[8675]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=debug msg="app state loaded" Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: touch_display: Volumio Kiosk started. Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: Completed starting Core Plugins Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: ------------------------------------------- Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: ----- MyVolumio plugins startup ---- Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: ------------------------------------------- Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 0 Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: No valid Plugin REST Endpoint Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: 20251221 15:32:10.115 [8700.8700] ERROR SampleApp: api request was not successful Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: Error: Application ID was not specified! Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -n|--deviceName: Device name Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -l|--model: Device's model name Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -s|--serialNumber: Device's serial number Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:10 volumio3840x2160 qobuz-connect[8700]: -h|--help: Print this help Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: touch_display: X display number found: 0 Dec 21 15:32:10 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:10 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: touch_display: X display number found: 0 Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+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:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+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:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+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:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=info msg="zeroconf server listening on port 40267" Dec 21 15:32:10 volumio3840x2160 volumio[8411]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=debug msg="obtained new client token: AAD5ovRaRqO0xxo6IKJQZfOxY8bYdIbLRIcGqyxOvaS8TnbIyVwlfdjL3P4f1UE4uolZ3IsVAAoPx+rw5ah5QsEKiTitOK7wrbQAxWGBOeEspne9HOALW4uyocTsN4jm4Hudyc1piNPEctAMkABxFrqDllABD39n0XtIKjhWYJnIk3T5RrlAZyDhf+etdno2o7g3vq974SlBqKuxtoKQuWS5A9lY03HHUYvtN++TDVHtk1jNpQhQJ7rSOA==" Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+01:00" level=debug msg="completed challenge" Dec 21 15:32:10 volumio3840x2160 go-librespot[8699]: time="2025-12-21T15:32:10+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:32:10 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:10 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:11 volumio3840x2160 volumio[8411]: info: Cannot mount NAS Music_GP at system boot, trial number 2 ,retrying in 5 seconds Dec 21 15:32:13 volumio3840x2160 volumio[8411]: info: go-librespot daemon successfully initialized Dec 21 15:32:13 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 21 15:32:13 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:13 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:13 volumio3840x2160 go-librespot[8717]: go-librespot daemon starting... Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=debug msg="app state loaded" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+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:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+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:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+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:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=info msg="zeroconf server listening on port 44225" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=debug msg="obtained new client token: AAB03I0tgkH+7qCvgLTwlgSh/EVxb4lBhImpXoEtTjrrI8ycK3X/pv92iG3Kwte9f0gy0PIk0W7NZic/BDvGndcTuDjmEQkNNBvbryj6HC340EkpAlDeaDFEa0LCcRrmnYfc7e2RLnmSWBf4LIuqwJTAwE5Kjk7XC/gWPPVbrEyYM70ha4pJsRuf+kPZ8s1FbfbPb7Z3ed9R/LXIcQkNvMtZI08X28SF3QLpX+A3bB4bCYdvQFaMNEIpdQ==" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=debug msg="completed challenge" Dec 21 15:32:13 volumio3840x2160 go-librespot[8718]: time="2025-12-21T15:32:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 21 15:32:13 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:13 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:15 volumio3840x2160 systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 2. Dec 21 15:32:15 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:15 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:15 volumio3840x2160 volumio[8411]: info: No valid Plugin REST Endpoint Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: 20251221 15:32:15.348 [8725.8725] ERROR SampleApp: api request was not successful Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: Error: Application ID was not specified! Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -n|--deviceName: Device name Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -l|--model: Device's model name Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -s|--serialNumber: Device's serial number Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:15 volumio3840x2160 qobuz-connect[8725]: -h|--help: Print this help Dec 21 15:32:15 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 33. Dec 21 15:32:15 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:15 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:15 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:32:15 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:32:15 volumio3840x2160 upmpdcli[8726]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:32:15 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:15 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:32:15 volumio3840x2160 volumio[8411]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 21 15:32:16 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:16 volumio3840x2160 volumio[8411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:16 volumio3840x2160 volumio[8411]: info: Cannot mount NAS Music_GP at system boot, trial number 3 ,retrying in 5 seconds Dec 21 15:32:17 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 21 15:32:17 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:17 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:17 volumio3840x2160 go-librespot[8742]: go-librespot daemon starting... Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=debug msg="app state loaded" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+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:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+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:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+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:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=info msg="zeroconf server listening on port 35763" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=debug msg="obtained new client token: AAD1hSkiKu3eH25nRKFK5wa7P++XmEw77xzpxUUri37R6J7Ke4REvVmDSPwF87w7bdBWErBAJ2N4yL9I9mHx27UwL3KT5kekkqe65bk9Ar4yN38pkvIKJQ/Z3cZNwWbVh08lSDxH7i20+vuFPIkfSmeC1d37/GDDGOhNFoYEN4OYyX+q9nT8m8O1qRe3/hlWsKN7pSJpdcMoIpHC4t6oJq0/dvVyiDoqE5M9WVqhm4k0WbyIl3Z3Esm32A==" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+01:00" level=debug msg="completed challenge" Dec 21 15:32:17 volumio3840x2160 go-librespot[8743]: time="2025-12-21T15:32:17+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:32:17 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:17 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioNext Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreStateMachine::next Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreStateMachine::stop Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreStateMachine::play index undefined Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreStateMachine::startPlaybackTimer Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:18 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::clearAddPlayTracks NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac Dec 21 15:32:18 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CoreStateMachine::updateTrackBlock Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrackBlock Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: sendMpdCommand stop took 1 milliseconds Dec 21 15:32:18 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand clear Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: sendMpdCommand clear took 1 milliseconds Dec 21 15:32:18 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac" Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:18 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces system playlist update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Ignoring MPD Status Update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:18 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces system playlist update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Ignoring MPD Status Update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: sendMpdCommand add "NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac" took 1 milliseconds Dec 21 15:32:18 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand play Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:18 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces system playlist update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Ignoring MPD Status Update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:18 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces system playlist update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Ignoring MPD Status Update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: ------------------------------ 3ms Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: ------------------------------ 2ms Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: sendMpdCommand play took 2 milliseconds Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: ------------------------------ 1ms Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: ------------------------------ 1ms Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:18 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces system playlist update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Ignoring MPD Status Update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:18 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces system playlist update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Ignoring MPD Status Update Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: ------------------------------ 1ms Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: ------------------------------ 1ms Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Adding plugin bluetooth to MyMusic Plugins Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Adding plugin multiroom to MyMusic Plugins Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Adding plugin metavolumio to MyMusic Plugins Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Adding plugin cd_controller to MyMusic Plugins Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 21 15:32:18 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Starting MyVolumio Remote Streaming Endpoints Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: MyVolumio login type: Token Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Streaming services startup Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Starting Streaming Daemon Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:19 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces state update: player Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::getState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:19 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces state update: player Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::getState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:19 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces state update: player Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:19 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces state update: player Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::getState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand status took 2 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::getState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand status took 1 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:32:19 volumio3840x2160 sudo[8756]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:19 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces state update: player Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::getState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Dec 21 15:32:19 volumio3840x2160 volumio[8411]: ---------------------------- MPD announces state update: player Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::getState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand status Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand status took 11 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand status took 10 milliseconds Dec 21 15:32:19 volumio3840x2160 sudo[8756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand playlistinfo took 9 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand playlistinfo took 9 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand status took 1 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:32:19 volumio3840x2160 sudo[8756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1493,"duration":136,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2492 Kbps","isStreaming":false,"title":"Misirlou (Theme From \"Pulp Fiction\")","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac","trackType":"flac"} Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: CURRENT POSITION 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState stateService play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState currentStatus stop Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1493,"duration":136,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2495 Kbps","isStreaming":false,"title":"Misirlou (Theme From \"Pulp Fiction\")","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac","trackType":"flac"} Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: CURRENT POSITION 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState stateService play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState currentStatus play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Received an update from plugin. extracting info from payload Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ------------------------------ 28ms Dec 21 15:32:19 volumio3840x2160 sudo[8756]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ------------------------------ 34ms Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand status took 25 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand playlistinfo took 24 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand playlistinfo took 24 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand playlistinfo took 24 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1493,"duration":136,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2495 Kbps","isStreaming":false,"title":"Misirlou (Theme From \"Pulp Fiction\")","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac","trackType":"flac"} Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: CURRENT POSITION 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState stateService play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState currentStatus play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Received an update from plugin. extracting info from payload Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1493,"duration":136,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2495 Kbps","isStreaming":false,"title":"Misirlou (Theme From \"Pulp Fiction\")","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac","trackType":"flac"} Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: CURRENT POSITION 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState stateService play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState currentStatus play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Received an update from plugin. extracting info from payload Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1493,"duration":136,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2495 Kbps","isStreaming":false,"title":"Misirlou (Theme From \"Pulp Fiction\")","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac","trackType":"flac"} Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: CURRENT POSITION 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState stateService play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState currentStatus play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Received an update from plugin. extracting info from payload Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ------------------------------ 71ms Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ------------------------------ 71ms Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ------------------------------ 61ms Dec 21 15:32:19 volumio3840x2160 volumio[8411]: error: Cannot start Volumio Streaming Daemon Dec 21 15:32:19 volumio3840x2160 volumio[8411]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 21 15:32:19 volumio3840x2160 volumio[8411]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:19 volumio3840x2160 volumio[8411]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: sendMpdCommand playlistinfo took 67 milliseconds Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: ControllerMpd::parseTrackInfo Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ControllerMpd::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1493,"duration":136,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2495 Kbps","isStreaming":false,"title":"Misirlou (Theme From \"Pulp Fiction\")","artist":"2Cellos","album":"2Cellos [Vinyl]","uri":"NAS/Music_GP/01 Progresive - Psychadelic - Smooth - Electronic/2Cellos/[2011] 2Cellos [Vinyl]/A2 Misirlou (Theme From Pulp Fiction).flac","trackType":"flac"} Dec 21 15:32:19 volumio3840x2160 volumio[8411]: verbose: CURRENT POSITION 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState stateService play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::syncState currentStatus play Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: Received an update from plugin. extracting info from payload Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:19 volumio3840x2160 volumio[8411]: info: ------------------------------ 104ms Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MyVolumio token set successfully Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MYVOLUMIO: Adding device Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MYVOLUMIO: Evaluating Server Dec 21 15:32:20 volumio3840x2160 systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 3. Dec 21 15:32:20 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 21 15:32:20 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:20 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:20 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:20 volumio3840x2160 go-librespot[8770]: go-librespot daemon starting... Dec 21 15:32:20 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=debug msg="app state loaded" Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MyVolumio Plan changed: premium Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Removing browser output: myVolumio user plan is not superstar Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Removing audio output: Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MYVOLUMIO: Adding device Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MYVOLUMIO: Evaluating Server Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: No valid Plugin REST Endpoint Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: 20251221 15:32:20.634 [8780.8780] ERROR SampleApp: api request was not successful Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: Error: Application ID was not specified! Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -n|--deviceName: Device name Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -l|--model: Device's model name Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -s|--serialNumber: Device's serial number Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:20 volumio3840x2160 qobuz-connect[8780]: -h|--help: Print this help Dec 21 15:32:20 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Remote config written successfully Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Starting Tunnel 1 Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Starting Tunnel Connection Checker Dec 21 15:32:20 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Completed starting MyVolumio Plugin Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+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:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+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:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+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:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=info msg="zeroconf server listening on port 36917" Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MYVolumio Device enabled Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: MyVolumio status changed Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Streaming services startup Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: Starting Streaming Daemon Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=debug msg="obtained new client token: AAAfagONyMnL5EB6HrWITKiJ7PoEBIqUYiSkp33K/+ivQNu6qXmIDh+urZhd/R6O40Z5v1sFlQrpc6NYqaYlKWIY38XdYojCCgx+k9Jlyg2YNFIReN2Zp/teDX/23zJF2dfepDFWECMZ7bfGrpnT5SUX0IAIUbo4VWY1Jk3jvaKnQp/Ej5LHMUIIxSzp+L4itDfXhTJuO+mkIBx9HwBS24ITXjD66DEs4WKgx+hz+6y18GvShLyaQD+mzQ==" Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 21 15:32:20 volumio3840x2160 sudo[8811]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:20 volumio3840x2160 sudo[8811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 21 15:32:20 volumio3840x2160 sudo[8811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:20 volumio3840x2160 sudo[8811]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:20 volumio3840x2160 volumio[8411]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 21 15:32:20 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+01:00" level=debug msg="completed challenge" Dec 21 15:32:20 volumio3840x2160 go-librespot[8781]: time="2025-12-21T15:32:20+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:32:20 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:20 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 21 15:32:21 volumio3840x2160 sudo[8815]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 21 15:32:21 volumio3840x2160 sudo[8815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:21 volumio3840x2160 sudo[8815]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:21 volumio3840x2160 volumio[8411]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 volumio[8411]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: MultiRoom plugin initialized Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: STOPPING SNAPCLIENT Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: Snap server stop Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: STOPPING volumioStreaming Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 21 15:32:21 volumio3840x2160 sudo[8832]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 21 15:32:21 volumio3840x2160 sudo[8832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 21 15:32:21 volumio3840x2160 sudo[8834]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:21 volumio3840x2160 sudo[8834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 21 15:32:21 volumio3840x2160 sudo[8834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:21 volumio3840x2160 sudo[8836]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 21 15:32:21 volumio3840x2160 sudo[8838]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 21 15:32:21 volumio3840x2160 sudo[8838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 21 15:32:21 volumio3840x2160 sudo[8838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 21 15:32:21 volumio3840x2160 sudo[8838]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Preparing to generate the ALSA configuration file Dec 21 15:32:21 volumio3840x2160 sudo[8832]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:21 volumio3840x2160 sudo[8834]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:21 volumio3840x2160 sudo[8836]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Setting Geolocation for MyVolumio to eu9 Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Reading ALSA contributions from plugins. Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Setting Geolocation for MyVolumio to eu8 Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: Removed streaming files Dec 21 15:32:21 volumio3840x2160 volumio[8411]: error: Cannot start Volumio Streaming Daemon Dec 21 15:32:21 volumio3840x2160 volumio[8411]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 21 15:32:21 volumio3840x2160 volumio[8411]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 volumio[8411]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Cannot mount NAS Music_GP at system boot, trial number 4 ,retrying in 5 seconds Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: volumioStreaming STOPPED Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: SNAPSERVER STOPPED Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: SNAPCLIENT STOPPED Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Asound.conf file unchanged, so no further update is needed Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Output device has changed, restarting MPD Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Plugin multiroom disabled by user. Not starting Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Adding METAVOLUMIO REST API Endpoints Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Preparing CD Folders Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Adding CD REST API Endpoints Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Starting UDEV Watcher for CD Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: Detecting CD presence with UDEV Dec 21 15:32:21 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 21 15:32:21 volumio3840x2160 sudo[8844]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:32:21 volumio3840x2160 sudo[8844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:21 volumio3840x2160 sudo[8844]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:21 volumio3840x2160 sudo[8846]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:32:21 volumio3840x2160 sudo[8846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:21 volumio3840x2160 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 21 15:32:21 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:32:21 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:32:21 volumio3840x2160 systemd[1]: mpd.service: Consumed 1.473s CPU time. Dec 21 15:32:21 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:32:21 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:32:21 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:32:21 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:32:21 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:32:21 volumio3840x2160 sudo[8855]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8855]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:21 volumio3840x2160 sudo[8855]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:32:21 volumio3840x2160 sudo[8855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:32:21 volumio3840x2160 sudo[8855]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:22 volumio3840x2160 mpd[8857]: 2025-12-21T15:32:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 21 15:32:22 volumio3840x2160 systemd[1]: Started mpd.service - Music Player Daemon. Dec 21 15:32:22 volumio3840x2160 sudo[8846]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:24 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 21 15:32:24 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:24 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:24 volumio3840x2160 go-librespot[8860]: go-librespot daemon starting... Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=debug msg="app state loaded" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+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:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+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:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+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:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=info msg="zeroconf server listening on port 40747" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=debug msg="obtained new client token: AADYlllHof6ed4uF+b1cj0zW5chBplobw69lEs+0lC970bd31HTiutz27dH4zBDXkX2e0nd2iz3NqiFW7HlhzKwD6YFArcbsST24dlMz6cF2bPlnQtJJdAyl3VQHaYnnPSWRHUWFLCcO+Zn6OPYe21XGnrwCIMEBfr+s7XH9rWVSkHh1GGY1KahorCy7KE+hNPEG0p9dci9gul0jKo5O0+uW9QGbDS761yIzZzRN4kZ8dzpAoqu/OKHbEw==" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+01:00" level=debug msg="completed challenge" Dec 21 15:32:24 volumio3840x2160 go-librespot[8861]: time="2025-12-21T15:32:24+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:32:24 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:24 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:25 volumio3840x2160 systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 4. Dec 21 15:32:25 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:25 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:26 volumio3840x2160 volumio[8411]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Adding inputs REST Endpoints Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Scanning Audio Inputs Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Checking against Known Cards name Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [1766327546520] CoreMusicLibrary::Adding element HiFiBerry ADC Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:26 volumio3840x2160 volumio[8411]: Cannot find translation for source Spotify Dec 21 15:32:26 volumio3840x2160 volumio[8411]: Cannot find translation for source HiFiBerry ADC Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Checking against Known Cards name Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [1766327546526] CoreMusicLibrary::Adding element Dummy Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:26 volumio3840x2160 volumio[8411]: Cannot find translation for source Spotify Dec 21 15:32:26 volumio3840x2160 volumio[8411]: Cannot find translation for source HiFiBerry ADC Dec 21 15:32:26 volumio3840x2160 volumio[8411]: Cannot find translation for source Dummy Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Checking against Known Cards name Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Adding Server instance for streaming Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 21 15:32:26 volumio3840x2160 volumio[8411]: error: Hi Res Audio Failed Login: Missing Login Data Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Refreshing TIDAL token Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Stopping AccessToken refresher cron for QOBUZ Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: AccessToken refresher cron started for QOBUZ Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Adding QOBUZ REST API Endpoints Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Updating MyVolumio device info Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Updating MyVolumio device info Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 sudo[8887]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 sudo[8887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 21 15:32:26 volumio3840x2160 sudo[8887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Successfully Added MyVolumio device Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Successfully Added MyVolumio device Dec 21 15:32:26 volumio3840x2160 sudo[8887]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:26 volumio3840x2160 volumio[8411]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: MPD Permissions set Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: No valid Plugin REST Endpoint: qc_getconfig Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: 20251221 15:32:26.615 [8868.8868] ERROR SampleApp: api request was not successful Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: Error: Application ID was not specified! Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -n|--deviceName: Device name Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -l|--model: Device's model name Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -s|--serialNumber: Device's serial number Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:26 volumio3840x2160 qobuz-connect[8868]: -h|--help: Print this help Dec 21 15:32:26 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:26 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: error: updateQueue error: null Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Preparing to generate the ALSA configuration file Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Reading ALSA contributions from plugins. Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Asound.conf file unchanged, so no further update is needed Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Output device has changed, restarting MPD Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Preparing to generate the ALSA configuration file Dec 21 15:32:26 volumio3840x2160 sudo[8901]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 sudo[8901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 21 15:32:26 volumio3840x2160 sudo[8901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:26 volumio3840x2160 sudo[8903]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 sudo[8903]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:32:26 volumio3840x2160 sudo[8903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:26 volumio3840x2160 sudo[8903]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 21 15:32:26 volumio3840x2160 sudo[8905]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Reading ALSA contributions from plugins. Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: MPD Permissions set Dec 21 15:32:26 volumio3840x2160 sudo[8905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:32:26 volumio3840x2160 sudo[8905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Asound.conf file unchanged, so no further update is needed Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Output device has changed, restarting MPD Dec 21 15:32:26 volumio3840x2160 autossh[7582]: received signal to exit (15) Dec 21 15:32:26 volumio3840x2160 systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 systemd[1]: sshtunnel.service: Deactivated successfully. Dec 21 15:32:26 volumio3840x2160 systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:26 volumio3840x2160 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 21 15:32:26 volumio3840x2160 sudo[8901]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:26 volumio3840x2160 sudo[8917]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 autossh[8928]: port set to 0, monitoring disabled Dec 21 15:32:26 volumio3840x2160 autossh[8928]: starting ssh (count 1) Dec 21 15:32:26 volumio3840x2160 autossh[8928]: ssh child pid is 8931 Dec 21 15:32:26 volumio3840x2160 sudo[8917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 21 15:32:26 volumio3840x2160 sudo[8917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Remote SSH Started Dec 21 15:32:26 volumio3840x2160 sudo[8917]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:26 volumio3840x2160 sudo[8919]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 sudo[8919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 21 15:32:26 volumio3840x2160 sudo[8919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:26 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 21 15:32:26 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 21 15:32:26 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 21 15:32:26 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 21 15:32:26 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: MPD Permissions set Dec 21 15:32:26 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Dec 21 15:32:26 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 21 15:32:26 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Successfully Updated MyVolumio device Dec 21 15:32:26 volumio3840x2160 volumio[8411]: info: Access Token successfully retrieved Dec 21 15:32:26 volumio3840x2160 sudo[8935]: root : unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 sudo[8935]: sudo: unable to resolve host volumio3840x2160: System error Dec 21 15:32:26 volumio3840x2160 sudo[8935]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 21 15:32:26 volumio3840x2160 sudo[8935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 15:32:26 volumio3840x2160 sudo[8935]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:26 volumio3840x2160 volumiossh-tunnel[8931]: Warning: Permanently added '[eu8.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: Successfully Updated MyVolumio device Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: Successfully retrieved User Session From TIDAL Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: Successfully retrieved User Subscription From TIDAL Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: Adding TIDAL to Browse Sources Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: [1766327547347] CoreMusicLibrary::Adding element TIDAL Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 15:32:27 volumio3840x2160 volumio[8411]: Cannot find translation for source Spotify Dec 21 15:32:27 volumio3840x2160 volumio[8411]: Cannot find translation for source HiFiBerry ADC Dec 21 15:32:27 volumio3840x2160 volumio[8411]: Cannot find translation for source Dummy Dec 21 15:32:27 volumio3840x2160 volumio[8411]: Cannot find translation for source TIDAL Dec 21 15:32:27 volumio3840x2160 volumio[8411]: info: Adding TIDAL REST API Endpoints Dec 21 15:32:27 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 21 15:32:27 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:27 volumio3840x2160 mpd[8937]: 2025-12-21T15:32:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 21 15:32:27 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:27 volumio3840x2160 go-librespot[8938]: go-librespot daemon starting... Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=debug msg="app state loaded" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32: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-gew1.spotify.com:80]" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+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:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+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:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=info msg="zeroconf server listening on port 35807" Dec 21 15:32:27 volumio3840x2160 systemd[1]: Started mpd.service - Music Player Daemon. Dec 21 15:32:27 volumio3840x2160 sudo[8919]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:27 volumio3840x2160 sudo[8905]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:27 volumio3840x2160 volumio[8411]: error: MPD error: The expression evaluated to a falsy value: Dec 21 15:32:27 volumio3840x2160 volumio[8411]: assert.ok(self.idling) Dec 21 15:32:27 volumio3840x2160 volumio[8411]: error: The expression evaluated to a falsy value: Dec 21 15:32:27 volumio3840x2160 volumio[8411]: assert.ok(self.idling) Dec 21 15:32:27 volumio3840x2160 volumio[8411]: error: updateQueue error: null Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=debug msg="obtained new client token: AAAu0DIfhGS0luL3qcI9bjS03OGUvYPMzYEYmqZcTq8OlM1Tc/BUTikEFA+YW04B7Ab76k6Dt8z3vIhOqZKPD6w1Nymz993ZXeH4mTDspi1hjCG0/GPGb5HahfCcWoEy+geu8wnA0TLuEP9kdOj1YQ0lrNym5m3ENCkkfv09sWyl/AKcec86At3SIwneU2hzcFkTaa0qiJcWgW52o9tW9dC3AwKqPsZfp57zS//sA58PGG+bErnNEWOmzw==" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32:27+01:00" level=debug msg="completed challenge" Dec 21 15:32:27 volumio3840x2160 go-librespot[8939]: time="2025-12-21T15:32: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:32:27 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:27 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:29 volumio3840x2160 volumio[8411]: error: Unable to stop TidalConnect service: Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: TidalConnect service stoped! Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 21 15:32:29 volumio3840x2160 sudo[8957]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:29 volumio3840x2160 sudo[8957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 21 15:32:29 volumio3840x2160 sudo[8957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 15:32:29 volumio3840x2160 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 21 15:32:29 volumio3840x2160 sudo[8957]: pam_unix(sudo:session): session closed for user root Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Executing endpoint tc_getconfig Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 21 15:32:29 volumio3840x2160 vtcs[8960]: STARTING TidalConnect services, version: 1.5.2.56 Dec 21 15:32:29 volumio3840x2160 vtcs[8960]: STARTED TidalConnect services. Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Executing endpoint tc_connect Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Connecting to TidalConnect Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::servicePushState Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:29 volumio3840x2160 volumio[8411]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 21 15:32:30 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 34. Dec 21 15:32:30 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:32:30 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 21 15:32:30 volumio3840x2160 upmpdcli[8976]: Could not open config: /tmp/upmpdcli.conf Dec 21 15:32:30 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:30 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 21 15:32:31 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 21 15:32:31 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:31 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:31 volumio3840x2160 go-librespot[8977]: go-librespot daemon starting... Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=debug msg="app state loaded" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+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:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+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:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+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:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=info msg="zeroconf server listening on port 42769" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=debug msg="obtained new client token: AAB6UtOtd9r2cQXQrLWMFpLVZVgAwzFpXZSlbqGHYmJZvrugcaytqsg/N5Ot8HuqsVcGWZqz4JfTZNvUikVJKChcX9wOb9Vam6Lw1ob8MUSo12RNm3cSWb4UyJoNmIVvjDop/AWTJ4MFIhBeDF6iDlTvO8sNsQ18ry+GwDymNyf0SqjPDgtdNTxm+33c4EmvBnAhh5ZufYBmT7aFx6taGheX02B8pNjE2L0R1K3u60/QgQaykuC+x6QKPQ==" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32:31+01:00" level=debug msg="completed challenge" Dec 21 15:32:31 volumio3840x2160 go-librespot[8978]: time="2025-12-21T15:32: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:32:31 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:31 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:31 volumio3840x2160 systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 5. Dec 21 15:32:31 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:31 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:31 volumio3840x2160 volumio[8411]: info: No valid Plugin REST Endpoint: qc_getconfig Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: 20251221 15:32:31.839 [8985.8985] ERROR SampleApp: api request was not successful Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: Error: Application ID was not specified! Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -n|--deviceName: Device name Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -l|--model: Device's model name Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -s|--serialNumber: Device's serial number Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:31 volumio3840x2160 qobuz-connect[8985]: -h|--help: Print this help Dec 21 15:32:31 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:31 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:32 volumio3840x2160 volumio[8411]: error: Unable to start TidalConnect service: Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: TidalConnect service started! Dec 21 15:32:32 volumio3840x2160 volumio[8411]: [Metrics] CommandRouter: 27s 113.93ms Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumiosetStartupVolume Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: VolumeController:: Setting startup Volume 35 Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: VolumeController::SetAlsaVolume35 Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::Close All Modals sent Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::Close All Modals sent Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreStateMachine::pushState Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 15:32:32 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioPushState Dec 21 15:32:33 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 21 15:32:33 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 21 15:32:33 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 21 15:32:34 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 21 15:32:34 volumio3840x2160 volumio[8411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 21 15:32:34 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetState Dec 21 15:32:34 volumio3840x2160 volumio[8411]: info: CorePlayQueue::getTrack 1 Dec 21 15:32:34 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 21 15:32:34 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:34 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:34 volumio3840x2160 go-librespot[8989]: go-librespot daemon starting... Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=debug msg="app state loaded" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32: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-gew1.spotify.com:80]" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+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:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+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:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=info msg="zeroconf server listening on port 45215" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=debug msg="obtained new client token: AADOXWehQZAu8SpkdzB2CM9sz1qN+EJmEb32JQYZ5CsveVcXDrLUyNz7oizb2D2q3O2WwGXp/wlUNKZsQdqebbrl8FpgX22YvqRIkhUxrlyNqy1/W3fEKdTOphQNzssqp2uzniKzpfW2LdQEjEcPrv8UABEaONe+tWtFYy41bi5qCdIIjvZ24HZjyua/WjjPeyk+QBIpqgkaL4MK6C+16v5M6xZPL3uC2dCxYqvi4JfzN3nrGwbC4/PfJg==" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32:34+01:00" level=debug msg="completed challenge" Dec 21 15:32:34 volumio3840x2160 go-librespot[8990]: time="2025-12-21T15:32: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:32:34 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:34 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:35 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:35 volumio3840x2160 volumio[8411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:37 volumio3840x2160 systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 6. Dec 21 15:32:37 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:37 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:37 volumio3840x2160 volumio[8411]: info: No valid Plugin REST Endpoint: qc_getconfig Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: 20251221 15:32:37.115 [9013.9013] ERROR SampleApp: api request was not successful Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: Error: Application ID was not specified! Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -n|--deviceName: Device name Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -l|--model: Device's model name Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -s|--serialNumber: Device's serial number Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:37 volumio3840x2160 qobuz-connect[9013]: -h|--help: Print this help Dec 21 15:32:37 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:37 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:38 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 21 15:32:38 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:38 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:38 volumio3840x2160 go-librespot[9014]: go-librespot daemon starting... Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=debug msg="app state loaded" Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+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:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+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:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+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:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=info msg="zeroconf server listening on port 35549" Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=debug msg="obtained new client token: AAAEATqt9/Z6tGOKnUWjDJrrf+31o/+zm22NKUCe9CZjei0A0sWCW2qUsb8v+MC4YyJh3RkCT29A5V7TmjbUn/mf1wfnkWLJoOZdh74q2G2j/NWo5QuGQpN3lwQxUg4EXzhHNGMSn11cVBXx3Mi/+XiXKm+MevFNFyR5hNAENkRFJAZNmjiPjEn6jzzWhdeNPo/4j1N7ntCZuWQUWZ4D0GA9ZzAh3qYu4frkwqtKnomv5kyD+LqpORHJmg==" Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+01:00" level=debug msg="completed challenge" Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 21 15:32:38 volumio3840x2160 go-librespot[9015]: time="2025-12-21T15:32:38+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:32:38 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:38 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:38 volumio3840x2160 volumio-remote-updater[980]: Test mode enabled Dec 21 15:32:38 volumio3840x2160 volumio-remote-updater[980]: Alpha mode disabled Dec 21 15:32:38 volumio3840x2160 volumio-remote-updater[980]: Alpha legacy test mode disabled Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 21 15:32:38 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::volumioGetBrowseSources Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 21 15:32:39 volumio3840x2160 volumio[8411]: info: BOOT COMPLETED Dec 21 15:32:41 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 21 15:32:41 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:41 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 21 15:32:41 volumio3840x2160 go-librespot[9041]: go-librespot daemon starting... Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=info msg="running go-librespot 0.4.0" Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=debug msg="app state loaded" Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 21 15:32:41 volumio3840x2160 volumio[8411]: info: Initializing connection to go-librespot Websocket Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=debug msg="new websocket client" Dec 21 15:32:41 volumio3840x2160 volumio[8411]: info: Connection to go-librespot Websocket established Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+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:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+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:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+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:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=info msg="zeroconf server listening on port 42859" Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=debug msg="obtained new client token: AAB3H/dQ3QRB4lCkGjpEmCiOYXRgGc1/VDkHb20EyajTDg5wnineTXZo48ckdW0LbsJ3q3WSNj0jveWJH6SUgEp5O+UMD4F2G+iBBJPyONB9Rr2DGFOyADkS8qnRCoL6TRJIqwQ2geflRefBHabXwesCIPwbJa4IKV1+AdowTZyXjLd6Yksq3zylvFCkodMRQs2jP8A7WzuEWcIx/szGJjWRBBXOe/FgYR5m7grAHlSElC3BGBohgzr1SA==" Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=debug msg="completed keyexchange" Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+01:00" level=debug msg="completed challenge" Dec 21 15:32:41 volumio3840x2160 go-librespot[9042]: time="2025-12-21T15:32:41+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:32:41 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:41 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 21 15:32:41 volumio3840x2160 volumio[8411]: info: Connection to go-librespot Websocket closed Dec 21 15:32:42 volumio3840x2160 systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 7. Dec 21 15:32:42 volumio3840x2160 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:42 volumio3840x2160 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 21 15:32:42 volumio3840x2160 volumio[8411]: info: No valid Plugin REST Endpoint: qc_getconfig Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: 20251221 15:32:42.347 [9049.9049] ERROR SampleApp: api request was not successful Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: Error: Application ID was not specified! Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -m|--manufacturer: Manufacturer of the device Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -n|--deviceName: Device name Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -l|--model: Device's model name Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -s|--serialNumber: Device's serial number Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -o|--outputDevice: ALSA PCM device to play audio to Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -p|--port: Port to run the local configuration HTTP server on Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 21 15:32:42 volumio3840x2160 qobuz-connect[9049]: -h|--help: Print this help Dec 21 15:32:42 volumio3840x2160 systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 21 15:32:42 volumio3840x2160 systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 21 15:32:44 volumio3840x2160 volumio[8411]: info: Getting Spotify volume Dec 21 15:32:44 volumio3840x2160 volumio[8411]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 15:32:44 volumio3840x2160 volumio[8411]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 21 15:32:44 volumio3840x2160 volumio[8411]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 21 15:32:44 volumio3840x2160 volumio[8411]: errno: -111, Dec 21 15:32:44 volumio3840x2160 volumio[8411]: code: 'ECONNREFUSED', Dec 21 15:32:44 volumio3840x2160 volumio[8411]: syscall: 'connect', Dec 21 15:32:44 volumio3840x2160 volumio[8411]: address: '127.0.0.1', Dec 21 15:32:44 volumio3840x2160 volumio[8411]: port: 9879, Dec 21 15:32:44 volumio3840x2160 volumio[8411]: response: undefined Dec 21 15:32:44 volumio3840x2160 volumio[8411]: } Dec 21 15:32:44 volumio3840x2160 volumio[8411]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 15:32:44 volumio3840x2160 sudo[9064]: volumio : unable to resolve host volumio3840x2160: System error Dec 21 15:32:44 volumio3840x2160 sudo[9064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-21 15:31' Dec 21 15:32:44 volumio3840x2160 sudo[9064]: 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"