Apr 14 14:34:02 volumio-z83 volumio[273329]: info: MYVOLUMIO: Adding device Apr 14 14:34:02 volumio-z83 volumio[273329]: info: MYVOLUMIO: Evaluating Server Apr 14 14:34:03 volumio-z83 volumio[273329]: info: Setting Geolocation for MyVolumio to eu7 Apr 14 14:34:03 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:03 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:03 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:03 volumio-z83 volumio[273329]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 14:34:04 volumio-z83 volumio[273329]: info: Updating MyVolumio device info Apr 14 14:34:04 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:04 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:04 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:04 volumio-z83 volumio[273329]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 14:34:08 volumio-z83 volumio[273329]: verbose: New Socket.io Connection to 192.168.9.114 from 192.168.9.101 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumioGetState Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CorePlayQueue::getTrack 0 Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumioGetState Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CorePlayQueue::getTrack 0 Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 14:34:08 volumio-z83 volumio[273329]: info: Received Get System Info Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:34:08 volumio-z83 volumio[273329]: info: Discovery: Getting this device information Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumioGetState Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CorePlayQueue::getTrack 0 Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumioGetState Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CorePlayQueue::getTrack 0 Apr 14 14:34:08 volumio-z83 volumio[273329]: info: Listing playlists Apr 14 14:34:08 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 14 14:34:10 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 14:34:10 volumio-z83 volumio[273329]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Apr 14 14:34:10 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumioGetState Apr 14 14:34:10 volumio-z83 volumio[273329]: info: CorePlayQueue::getTrack 0 Apr 14 14:34:13 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:34:13 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:13 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 14:34:13 volumio-z83 volumio-remote-updater[855]: Test mode disabled Apr 14 14:34:13 volumio-z83 volumio-remote-updater[855]: Alpha mode disabled Apr 14 14:34:13 volumio-z83 volumio-remote-updater[855]: Alpha legacy test mode disabled Apr 14 14:34:13 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 14 14:34:14 volumio-z83 volumio[273329]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 14 14:34:14 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumioGetBrowseSources Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:34:15 volumio-z83 volumio[273329]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 14 14:34:15 volumio-z83 volumio[273329]: info: Completed starting MyVolumio Plugin Apr 14 14:34:15 volumio-z83 volumio[273329]: [Metrics] CommandRouter: 41s 264.71ms Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::volumiosetStartupVolume Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::Close All Modals sent Apr 14 14:34:15 volumio-z83 volumio[273329]: info: CoreCommandRouter::Close All Modals sent Apr 14 14:34:16 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 14 14:34:16 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 14 14:34:16 volumio-z83 volumio[273329]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 14 14:34:22 volumio-z83 volumio[273329]: info: BOOT COMPLETED Apr 14 14:35:20 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:20+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.9.114:42956->104.154.127.247:4070: read: connection reset by peer" Apr 14 14:35:20 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:20+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 14:35:20 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:20+02:00" level=debug msg="completed keyexchange" Apr 14 14:35:20 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:20+02:00" level=debug msg="completed challenge" Apr 14 14:35:20 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:20+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 14:35:21 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:21+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 14:35:22 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:22+02:00" level=debug msg="completed keyexchange" Apr 14 14:35:22 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:22+02:00" level=debug msg="completed challenge" Apr 14 14:35:22 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:22+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 14 14:35:22 volumio-z83 go-librespot[273568]: time="2026-04-14T14:35:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 14 14:35:22 volumio-z83 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 14:35:22 volumio-z83 volumio[273329]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 14:35:22 volumio-z83 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 14:35:22 volumio-z83 volumio[273329]: Error: socket hang up Apr 14 14:35:22 volumio-z83 volumio[273329]: at connResetException (node:internal/errors:720:14) Apr 14 14:35:22 volumio-z83 volumio[273329]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 14:35:22 volumio-z83 volumio[273329]: at Socket.emit (node:events:526:35) Apr 14 14:35:22 volumio-z83 volumio[273329]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 14:35:22 volumio-z83 volumio[273329]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 14:35:22 volumio-z83 volumio[273329]: code: 'ECONNRESET', Apr 14 14:35:22 volumio-z83 volumio[273329]: response: undefined Apr 14 14:35:22 volumio-z83 volumio[273329]: } Apr 14 14:35:22 volumio-z83 volumio[273329]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 14:35:22 volumio-z83 sudo[274005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 14:34' Apr 14 14:35:22 volumio-z83 sudo[274005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"