Dec 22 13:35:53 volumio3840x2160 ntpd[1195]: CLOCK: time stepped by 78154.781135 Dec 22 13:35:53 volumio3840x2160 ntpd[1195]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 22 13:35:53 volumio3840x2160 sudo[2268]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:53 volumio3840x2160 sudo[2270]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:53 volumio3840x2160 sudo[2268]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 13:35:53 volumio3840x2160 sudo[2268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:53 volumio3840x2160 sudo[2270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 13:35:53 volumio3840x2160 sudo[2270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:53 volumio3840x2160 sudo[2268]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:53 volumio3840x2160 sudo[2270]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: MyVolumio Plan changed: premium Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Removing browser output: myVolumio user plan is not superstar Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Removing audio output: Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: MYVOLUMIO: Adding device Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: MYVOLUMIO: Evaluating Server Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Remote config written successfully Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Starting Tunnel 1 Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Starting Tunnel Connection Checker Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Completed starting MyVolumio Plugin Dec 22 13:35:53 volumio3840x2160 volumio[1369]: 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: 8 Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: MYVolumio Device enabled Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: MyVolumio status changed Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Streaming services startup Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Starting Streaming Daemon Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 22 13:35:53 volumio3840x2160 volumio[1369]: error: [MyVolumio PluginManager] Cache data is invalid! Dec 22 13:35:53 volumio3840x2160 sudo[2310]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:53 volumio3840x2160 sudo[2310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 22 13:35:53 volumio3840x2160 sudo[2310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:53 volumio3840x2160 sudo[2312]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:53 volumio3840x2160 sudo[2312]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 13:35:53 volumio3840x2160 sudo[2312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:53 volumio3840x2160 sudo[2312]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:53 volumio3840x2160 sudo[2314]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:53 volumio3840x2160 sudo[2314]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 13:35:53 volumio3840x2160 sudo[2314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:53 volumio3840x2160 sudo[2314]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:53 volumio3840x2160 systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Dec 22 13:35:53 volumio3840x2160 systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Dec 22 13:35:53 volumio3840x2160 sudo[2310]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Discovery: A device disappeared from network Dec 22 13:35:53 volumio3840x2160 systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Discovery: A device disappeared from network Dec 22 13:35:53 volumio3840x2160 volumio[1369]: error: Cannot start Volumio Streaming Daemon Dec 22 13:35:53 volumio3840x2160 volumio[1369]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 22 13:35:53 volumio3840x2160 volumio[1369]: sudo: unable to resolve host volumio3840x2160: System error Dec 22 13:35:53 volumio3840x2160 volumio[1369]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 22 13:35:53 volumio3840x2160 volumio[1369]: info: Discovery: A device disappeared from network Dec 22 13:35:53 volumio3840x2160 systemd[1]: dpkg-db-backup.service: Deactivated successfully. Dec 22 13:35:53 volumio3840x2160 systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Dec 22 13:35:53 volumio3840x2160 volumio[1369]: 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: 9 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Setting Geolocation for MyVolumio to eu8 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Discovery: adding 7d7396b9-8aeb-472a-9bf4-4627ea7d6f66 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Discovery: Found device Volumio_3840x2160 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Discovery: this is already registered, 7d7396b9-8aeb-472a-9bf4-4627ea7d6f66 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Discovery: Found device Volumio_3840x2160 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetVisibleSources Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Received Get System Info Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Discovery: Getting this device information Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Listing playlists Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Discovery: adding 18c68c60-8d45-4559-bace-e0c72dc40d5b Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Discovery: Found device Volumio_1920x1080 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Setting Geolocation for MyVolumio to eu5 Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: Successfully Added MyVolumio device Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 22 13:35:54 volumio3840x2160 volumio[1369]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 22 13:35:54 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 22 13:35:55 volumio3840x2160 sudo[2335]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 22 13:35:55 volumio3840x2160 sudo[2335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:55 volumio3840x2160 sudo[2335]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:55 volumio3840x2160 volumio[1369]: sudo: unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: MultiRoom plugin initialized Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: STOPPING SNAPCLIENT Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: Snap server stop Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: STOPPING volumioStreaming Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 22 13:35:55 volumio3840x2160 sudo[2352]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 22 13:35:55 volumio3840x2160 sudo[2352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 22 13:35:55 volumio3840x2160 sudo[2352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:55 volumio3840x2160 sudo[2354]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 22 13:35:55 volumio3840x2160 sudo[2354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 22 13:35:55 volumio3840x2160 sudo[2356]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2358]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 22 13:35:55 volumio3840x2160 sudo[2358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 22 13:35:55 volumio3840x2160 sudo[2356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:55 volumio3840x2160 sudo[2358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:55 volumio3840x2160 sudo[2358]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 22 13:35:55 volumio3840x2160 sudo[2352]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Preparing to generate the ALSA configuration file Dec 22 13:35:55 volumio3840x2160 sudo[2354]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:55 volumio3840x2160 sudo[2356]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Updating MyVolumio device info Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Updating MyVolumio device info Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Initializing connection to go-librespot Websocket Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Reading ALSA contributions from plugins. Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Successfully Added MyVolumio device Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: Removed streaming files Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: volumioStreaming STOPPED Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: SNAPSERVER STOPPED Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: SNAPCLIENT STOPPED Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Asound.conf file unchanged, so no further update is needed Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Output device has changed, restarting MPD Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Plugin multiroom disabled by user. Not starting Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Adding METAVOLUMIO REST API Endpoints Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Preparing CD Folders Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Adding CD REST API Endpoints Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Starting UDEV Watcher for CD Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: Detecting CD presence with UDEV Dec 22 13:35:55 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 22 13:35:55 volumio3840x2160 sudo[2364]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 13:35:55 volumio3840x2160 sudo[2366]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 13:35:55 volumio3840x2160 sudo[2366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:55 volumio3840x2160 sudo[2364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:35:55 volumio3840x2160 sudo[2364]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:55 volumio3840x2160 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 22 13:35:55 volumio3840x2160 systemd[1]: mpd.service: Deactivated successfully. Dec 22 13:35:55 volumio3840x2160 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 22 13:35:55 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 22 13:35:55 volumio3840x2160 systemd[1]: mpd.socket: Deactivated successfully. Dec 22 13:35:55 volumio3840x2160 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 22 13:35:55 volumio3840x2160 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 22 13:35:55 volumio3840x2160 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 22 13:35:55 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:35:55 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:35:55 volumio3840x2160 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 22 13:35:55 volumio3840x2160 go-librespot[2375]: go-librespot daemon starting... Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=debug msg="app state loaded" Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 13:35:55 volumio3840x2160 sudo[2376]: root : unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2376]: sudo: unable to resolve host volumio3840x2160: System error Dec 22 13:35:55 volumio3840x2160 sudo[2376]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 22 13:35:55 volumio3840x2160 sudo[2376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 22 13:35:55 volumio3840x2160 sudo[2376]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+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 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+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 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+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 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=info msg="zeroconf server listening on port 46723" Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=debug msg="obtained new client token: AACySorlfo2qYS9UE7X6mPOrD1ywYXMHOTt2YYM50Cpr4ToDpeb/AxBXQ+JyuZc3oK1um26JgFRycR/40v95F8oiiaWgHNZfoWPV9/XBmtdBKJnbYGrqkphGPL99A2FPixgJxDynwtNoZBVMlizt4OGWty7GSW5NdMx0BNuucL/XfWR9sbf+v9EWqiHCVkNFoVNnBpxNX3GBhpqXRQF81NEHJ0OzU21zb3u/jMYJ1BsxKWNHhV2jFcHz0A==" Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=debug msg="completed keyexchange" Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+01:00" level=debug msg="completed challenge" Dec 22 13:35:55 volumio3840x2160 go-librespot[2377]: time="2025-12-22T13:35:55+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 22 13:35:55 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 13:35:55 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 13:35:55 volumio3840x2160 mpd[2386]: 2025-12-22T13:35:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 13:35:55 volumio3840x2160 systemd[1]: Started mpd.service - Music Player Daemon. Dec 22 13:35:55 volumio3840x2160 sudo[2366]: pam_unix(sudo:session): session closed for user root Dec 22 13:35:58 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 22 13:35:58 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:35:58 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:35:58 volumio3840x2160 go-librespot[2390]: go-librespot daemon starting... Dec 22 13:35:58 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:58+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 13:35:58 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:58+01:00" level=debug msg="app state loaded" Dec 22 13:35:58 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+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 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+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 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+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 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+01:00" level=info msg="zeroconf server listening on port 44515" Dec 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+01:00" level=debug msg="obtained new client token: AABGKEaFr2vQPaAznSWwHuZ4qgs6Hi3suLy6oafdsMPC68Kr41gxu9oPS/6yyIbzuo0vVZVgGfPm5MN9w4wJRiX94kzW0z28exPMZdws7DI+FReM2KseY9GOpDL9xI14dCEoSlT8KmI1hQCP73rcFi1YHO0jt6ehMw3HZcw5XSWAKqN5ttXnEBrrYaWJNtUjLcr+5Qoao9YA7EqQt9Fi0jnCenihotIz5lVzU30/N6nljYDMv7b7NkY=" Dec 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+01:00" level=debug msg="completed keyexchange" Dec 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+01:00" level=debug msg="completed challenge" Dec 22 13:35:59 volumio3840x2160 go-librespot[2391]: time="2025-12-22T13:35:59+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 22 13:35:59 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 13:35:59 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 13:36:00 volumio3840x2160 volumio[1369]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Adding inputs REST Endpoints Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Scanning Audio Inputs Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Checking against Known Cards name Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [1766406960278] CoreMusicLibrary::Adding element HiFiBerry ADC Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 13:36:00 volumio3840x2160 volumio[1369]: Cannot find translation for source HiFiBerry ADC Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Checking against Known Cards name Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [1766406960281] CoreMusicLibrary::Adding element Dummy Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 13:36:00 volumio3840x2160 volumio[1369]: Cannot find translation for source HiFiBerry ADC Dec 22 13:36:00 volumio3840x2160 volumio[1369]: Cannot find translation for source Dummy Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Checking against Known Cards name Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Adding Server instance for streaming Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 22 13:36:00 volumio3840x2160 volumio[1369]: error: Hi Res Audio Failed Login: Missing Login Data Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Refreshing TIDAL token Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Stopping AccessToken refresher cron for QOBUZ Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: AccessToken refresher cron started for QOBUZ Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Adding QOBUZ REST API Endpoints Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Initializing connection to go-librespot Websocket Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Successfully Updated MyVolumio device Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Successfully Updated MyVolumio device Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Received Get System Info Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Discovery: Getting this device information Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Received Get System Info Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Discovery: Getting this device information Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: MPD Permissions set Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: error: updateQueue error: null Dec 22 13:36:00 volumio3840x2160 sudo[2416]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:36:00 volumio3840x2160 sudo[2416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 13:36:00 volumio3840x2160 sudo[2416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:36:00 volumio3840x2160 sudo[2416]: pam_unix(sudo:session): session closed for user root Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Dec 22 13:36:00 volumio3840x2160 sudo[2449]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:36:00 volumio3840x2160 sudo[2449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 22 13:36:00 volumio3840x2160 sudo[2449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:36:00 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 22 13:36:00 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 22 13:36:00 volumio3840x2160 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 13:36:00 volumio3840x2160 sudo[2449]: pam_unix(sudo:session): session closed for user root Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Remote SSH Started Dec 22 13:36:00 volumio3840x2160 autossh[2452]: port set to 0, monitoring disabled Dec 22 13:36:00 volumio3840x2160 autossh[2452]: starting ssh (count 1) Dec 22 13:36:00 volumio3840x2160 autossh[2452]: ssh child pid is 2455 Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Received Get System Version Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 13:36:00 volumio3840x2160 volumio[1369]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:00 volumio3840x2160 volumiossh-tunnel[2455]: Warning: Permanently added '[eu5.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 22 13:36:00 volumio3840x2160 volumio[1369]: info: Access Token successfully retrieved Dec 22 13:36:01 volumio3840x2160 volumio[1369]: info: Successfully retrieved User Session From TIDAL Dec 22 13:36:01 volumio3840x2160 systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 22 13:36:01 volumio3840x2160 volumio[1369]: info: Successfully retrieved User Subscription From TIDAL Dec 22 13:36:01 volumio3840x2160 volumio[1369]: info: Adding TIDAL to Browse Sources Dec 22 13:36:01 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 13:36:01 volumio3840x2160 volumio[1369]: info: [1766406961244] CoreMusicLibrary::Adding element TIDAL Dec 22 13:36:01 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 13:36:01 volumio3840x2160 volumio[1369]: Cannot find translation for source HiFiBerry ADC Dec 22 13:36:01 volumio3840x2160 volumio[1369]: Cannot find translation for source Dummy Dec 22 13:36:01 volumio3840x2160 volumio[1369]: Cannot find translation for source TIDAL Dec 22 13:36:01 volumio3840x2160 volumio[1369]: info: Adding TIDAL REST API Endpoints Dec 22 13:36:01 volumio3840x2160 nmbd[1253]: [2025/12/22 13:36:01.502491, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Dec 22 13:36:01 volumio3840x2160 nmbd[1253]: register_name_response: Answer name <00> differs from question name <00>. Dec 22 13:36:01 volumio3840x2160 nmbd[1253]: [2025/12/22 13:36:01.502628, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Dec 22 13:36:01 volumio3840x2160 nmbd[1253]: register_name_response: Answer name <03> differs from question name <03>. Dec 22 13:36:01 volumio3840x2160 nmbd[1253]: [2025/12/22 13:36:01.502681, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Dec 22 13:36:01 volumio3840x2160 nmbd[1253]: register_name_response: Answer name <20> differs from question name <20>. Dec 22 13:36:02 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 22 13:36:02 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:36:02 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:36:02 volumio3840x2160 go-librespot[2457]: go-librespot daemon starting... Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=debug msg="app state loaded" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+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 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+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 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+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 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=info msg="zeroconf server listening on port 37239" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=debug msg="obtained new client token: AABXHLETKO+Liq4QI2MJ7Rvpwur82hlh9qfK7hSAvj2z4B/paGIHKMwWHDB6WzoiAtINwC6CijXbZOX4X18MBsQFb4iyaVfqXCi/rDxITHWQb61w2DIkFGv1KV+Vs7B0oyn0uvSrqZ64naHTicTe6kSX48TZtUNSdft9CNzgdIWwUpbj00IPgX31duyYlEaFt6LwjoGwGn4NMF4sbEi7KSNEb9MQSBgJbhMQUjK55TjjaxdkSwTx8xQ+lw==" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=debug msg="completed keyexchange" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=debug msg="completed challenge" Dec 22 13:36:02 volumio3840x2160 go-librespot[2458]: time="2025-12-22T13:36:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Dec 22 13:36:02 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 13:36:02 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 13:36:03 volumio3840x2160 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Initializing connection to go-librespot Websocket Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 13:36:03 volumio3840x2160 volumio[1369]: error: Unable to stop TidalConnect service: Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: TidalConnect service stoped! Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 13:36:03 volumio3840x2160 sudo[2477]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:36:03 volumio3840x2160 sudo[2477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 13:36:03 volumio3840x2160 sudo[2477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 13:36:03 volumio3840x2160 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 22 13:36:03 volumio3840x2160 sudo[2477]: pam_unix(sudo:session): session closed for user root Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Executing endpoint tc_getconfig Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 22 13:36:03 volumio3840x2160 vtcs[2480]: STARTING TidalConnect services, version: 1.5.2.56 Dec 22 13:36:03 volumio3840x2160 vtcs[2480]: STARTED TidalConnect services. Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Executing endpoint tc_connect Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Connecting to TidalConnect Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::servicePushState Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreStateMachine::pushState Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioPushState Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::servicePushState Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreStateMachine::pushState Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioPushState Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Dec 22 13:36:03 volumio3840x2160 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 22 13:36:03 volumio3840x2160 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 13:36:03 volumio3840x2160 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 22 13:36:03 volumio3840x2160 upmpdcli[2496]: Could not open config: /tmp/upmpdcli.conf Dec 22 13:36:03 volumio3840x2160 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 22 13:36:03 volumio3840x2160 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 22 13:36:03 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 22 13:36:05 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 22 13:36:05 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:36:05 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:36:05 volumio3840x2160 go-librespot[2497]: go-librespot daemon starting... Dec 22 13:36:05 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:05+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 13:36:05 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:05+01:00" level=debug msg="app state loaded" Dec 22 13:36:05 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+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 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+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 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+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 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+01:00" level=info msg="zeroconf server listening on port 45827" Dec 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+01:00" level=debug msg="obtained new client token: AAA5h6WF5PL9pNG4XJB2AgNsKU9kJM4OXn4vvymTTWLHYareLMZvlXrPQ3W8BSHrzlirslY2ABu2rcPd46kFnWfDVhljxiH2F0wd5DTHhsimBBEUuUfWRKs6Nx9rXFIOKY+5EbKAqnY7GRW4wbb3Mo/Cl5caLJ8+jJfPA0AvX/2ryCI38MdnD6FRe0w3lg91IhUhHGXHsdpiTnheZhKveVZ1U2AvHl8BYCxYa4vRrUdIateJ1rcJnqY=" Dec 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+01:00" level=debug msg="completed keyexchange" Dec 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+01:00" level=debug msg="completed challenge" Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: Initializing connection to go-librespot Websocket Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: Connection to go-librespot Websocket established Dec 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+01:00" level=debug msg="new websocket client" Dec 22 13:36:06 volumio3840x2160 go-librespot[2498]: time="2025-12-22T13:36:06+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 22 13:36:06 volumio3840x2160 volumio[1369]: info: Connection to go-librespot Websocket closed Dec 22 13:36:06 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 22 13:36:06 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 22 13:36:06 volumio3840x2160 volumio[1369]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioGetState Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:06 volumio3840x2160 volumio[1369]: error: Unable to start TidalConnect service: Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: TidalConnect service started! Dec 22 13:36:06 volumio3840x2160 volumio[1369]: [Metrics] CommandRouter: 28s 349.53ms Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumiosetStartupVolume Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: VolumeController:: Setting startup Volume 35 Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: VolumeController::SetAlsaVolume35 Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::Close All Modals sent Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::Close All Modals sent Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreStateMachine::pushState Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CorePlayQueue::getTrack 0 Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 13:36:06 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::volumioPushState Dec 22 13:36:07 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 22 13:36:07 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 13:36:07 volumio3840x2160 volumio[1369]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 22 13:36:09 volumio3840x2160 volumio[1369]: info: Getting Spotify volume Dec 22 13:36:09 volumio3840x2160 volumio[1369]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 13:36:09 volumio3840x2160 volumio[1369]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 22 13:36:09 volumio3840x2160 volumio[1369]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 22 13:36:09 volumio3840x2160 volumio[1369]: errno: -111, Dec 22 13:36:09 volumio3840x2160 volumio[1369]: code: 'ECONNREFUSED', Dec 22 13:36:09 volumio3840x2160 volumio[1369]: syscall: 'connect', Dec 22 13:36:09 volumio3840x2160 volumio[1369]: address: '127.0.0.1', Dec 22 13:36:09 volumio3840x2160 volumio[1369]: port: 9879, Dec 22 13:36:09 volumio3840x2160 volumio[1369]: response: undefined Dec 22 13:36:09 volumio3840x2160 volumio[1369]: } Dec 22 13:36:09 volumio3840x2160 volumio[1369]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 13:36:09 volumio3840x2160 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 22 13:36:09 volumio3840x2160 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:36:09 volumio3840x2160 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 22 13:36:09 volumio3840x2160 go-librespot[2535]: go-librespot daemon starting... Dec 22 13:36:09 volumio3840x2160 go-librespot[2536]: time="2025-12-22T13:36:09+01:00" level=info msg="running go-librespot 0.4.0" Dec 22 13:36:09 volumio3840x2160 go-librespot[2536]: time="2025-12-22T13:36:09+01:00" level=debug msg="app state loaded" Dec 22 13:36:09 volumio3840x2160 go-librespot[2536]: time="2025-12-22T13:36:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 22 13:36:09 volumio3840x2160 sudo[2544]: volumio : unable to resolve host volumio3840x2160: System error Dec 22 13:36:09 volumio3840x2160 sudo[2544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-22 13:35' Dec 22 13:36:09 volumio3840x2160 sudo[2544]: 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"