Aug 27 06:14:09 volumio-nuc ntpd[944]: CLOCK: time stepped by 14549801.577746
Aug 27 06:14:09 volumio-nuc ntpd[944]: CLOCK: time changed from 2026-03-11 to 2026-08-27
Aug 27 06:14:09 volumio-nuc ntpd[944]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: A device disappeared from network
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: A device disappeared from network
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: A device disappeared from network
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: A device disappeared from network
Aug 27 06:14:09 volumio-nuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Aug 27 06:14:09 volumio-nuc systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service...
Aug 27 06:14:09 volumio-nuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 27 06:14:09 volumio-nuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 27 06:14:09 volumio-nuc systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats.
Aug 27 06:14:09 volumio-nuc go-librespot[1962]: go-librespot daemon starting...
Aug 27 06:14:09 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:09Z" level=info msg="running go-librespot 0.6.2"
Aug 27 06:14:09 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:09Z" level=debug msg="app state loaded"
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Volumio called home
Aug 27 06:14:09 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:09Z" level=info msg="api server listening on 127.0.0.1:9879"
Aug 27 06:14:09 volumio-nuc systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully.
Aug 27 06:14:09 volumio-nuc systemd[1]: dpkg-db-backup.service: Deactivated successfully.
Aug 27 06:14:09 volumio-nuc systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service.
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: adding da613da1-2f16-4d40-bda3-a74a1b89c70b
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: Found device Volumio nuc
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: CoreCommandRouter::volumioGetState
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: CorePlayQueue::getTrack 0
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: this is already registered, da613da1-2f16-4d40-bda3-a74a1b89c70b
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: Found device Volumio nuc
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: CoreCommandRouter::volumioGetState
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: CorePlayQueue::getTrack 0
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: adding 8d0d72b3-5195-4316-aa07-5e5dfbe55115
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: Found device Studio
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: adding 4ecff229-156c-4457-a9de-76de336d79f2
Aug 27 06:14:09 volumio-nuc volumio[1063]: info: Discovery: Found device SofaRoom4
Aug 27 06:14:09 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:09Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Aug 27 06:14:09 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:09Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Aug 27 06:14:09 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:09Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Aug 27 06:14:09 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:09Z" level=info msg="zeroconf server listening on port 39361"
Aug 27 06:14:10 volumio-nuc upmpdcli[1987]: writing RSA key
Aug 27 06:14:10 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:10Z" level=debug msg="obtained new client token: AAFgOyacz94ksHI0RruO9al11Z4JJkFoTGFgku4Jl7/qgdRAQojiek9KdUEHPZbrDjY/9xs8dKz+u6ENQmGWoWnhcNu8c3tZCD62Ey4hiUPBLkd4xz2L3M/w9/whK21q5JygedbgdWb37hbosjU5Q3Er8jz0cRljAMxooSD4iah0NjS2D8ZW6um2dI5JGiiAO9ncP35N1PP6p5JLCAj148EbKr00jO0+Ux7+INIdJFcBmbQMj57FtaE="
Aug 27 06:14:10 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:10Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Aug 27 06:14:10 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:10Z" level=debug msg="completed keyexchange"
Aug 27 06:14:10 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:10Z" level=debug msg="completed challenge"
Aug 27 06:14:10 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:10Z" level=info msg="authenticated AP" username="js*****60"
Aug 27 06:14:10 volumio-nuc go-librespot[1964]: time="2026-08-27T06:14:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 27 06:14:10 volumio-nuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 27 06:14:10 volumio-nuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 27 06:14:11 volumio-nuc sudo[1887]: pam_unix(sudo:session): session closed for user root
Aug 27 06:14:11 volumio-nuc volumio[1063]: info: Cannot mount NAS DS918 at system boot, trial number 2 ,retrying in 5 seconds
Aug 27 06:14:11 volumio-nuc volumio[1063]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Aug 27 06:14:11 volumio-nuc volumio[1063]: info: Initializing connection to go-librespot Websocket
Aug 27 06:14:11 volumio-nuc volumio[1063]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 27 06:14:13 volumio-nuc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Aug 27 06:14:13 volumio-nuc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 27 06:14:13 volumio-nuc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 27 06:14:13 volumio-nuc go-librespot[2027]: go-librespot daemon starting...
Aug 27 06:14:13 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:13Z" level=info msg="running go-librespot 0.6.2"
Aug 27 06:14:13 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:13Z" level=debug msg="app state loaded"
Aug 27 06:14:13 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:13Z" level=info msg="api server listening on 127.0.0.1:9879"
Aug 27 06:14:14 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:14Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 27 06:14:14 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:14Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 27 06:14:14 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:14Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 27 06:14:14 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:14Z" level=info msg="zeroconf server listening on port 45871"
Aug 27 06:14:14 volumio-nuc volumio[1063]: info: Initializing connection to go-librespot Websocket
Aug 27 06:14:14 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:14Z" level=debug msg="new websocket client"
Aug 27 06:14:14 volumio-nuc volumio[1063]: info: Connection to go-librespot Websocket established
Aug 27 06:14:14 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:14Z" level=debug msg="obtained new client token: AAGKPOMWNnIV1UHPDbr+wvpEmglzKAtM+4pc7PuTMh7NtKFnrTRaQ8ihj+rbGSzdqJ5o5/5UdkjtT6uAK7Rk71bbyiXKdBznxnvN/UMi21NY0xBvXJjCCMI+Xe7dWL+BpxfuaCCFf7fT28CktYzy7c+YnOvRcuSzyAABJeEmC7ADySCjjG+YBXTXnlqRum4ZQKCABQXxd+UkA/1PhnO/aANTHXEIGAhDdyRnguUIClR7dqr01WbEpehUTQ=="
Aug 27 06:14:14 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:14Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused"
Aug 27 06:14:15 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:15Z" level=debug msg="connected to ap-gew1.spotify.com:443"
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: Received Get System Info
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: Discovery: Getting this device information
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: CoreCommandRouter::volumioGetState
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: CorePlayQueue::getTrack 0
Aug 27 06:14:15 volumio-nuc volumio[1063]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 27 06:14:15 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:15Z" level=debug msg="completed keyexchange"
Aug 27 06:14:15 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:15Z" level=debug msg="completed challenge"
Aug 27 06:14:15 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:15Z" level=info msg="authenticated AP" username="js*****60"
Aug 27 06:14:16 volumio-nuc go-librespot[2028]: time="2026-08-27T06:14:16Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 27 06:14:16 volumio-nuc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 27 06:14:16 volumio-nuc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 27 06:14:16 volumio-nuc volumio[1063]: info: Connection to go-librespot Websocket closed
Aug 27 06:14:16 volumio-nuc volumio[1063]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Aug 27 06:14:16 volumio-nuc sudo[2040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.1.123:/volume1/music /mnt/NAS/DS918
Aug 27 06:14:16 volumio-nuc sudo[2040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 27 06:14:17 volumio-nuc volumio[1063]: info: Getting Spotify volume
Aug 27 06:14:17 volumio-nuc volumio[1063]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 27 06:14:17 volumio-nuc volumio[1063]: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 27 06:14:17 volumio-nuc volumio[1063]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Aug 27 06:14:17 volumio-nuc volumio[1063]: errno: -111,
Aug 27 06:14:17 volumio-nuc volumio[1063]: code: 'ECONNREFUSED',
Aug 27 06:14:17 volumio-nuc volumio[1063]: syscall: 'connect',
Aug 27 06:14:17 volumio-nuc volumio[1063]: address: '127.0.0.1',
Aug 27 06:14:17 volumio-nuc volumio[1063]: port: 9879,
Aug 27 06:14:17 volumio-nuc volumio[1063]: response: undefined
Aug 27 06:14:17 volumio-nuc volumio[1063]: }
Aug 27 06:14:17 volumio-nuc volumio[1063]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 27 06:14:17 volumio-nuc sudo[2077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-27 06:13'
Aug 27 06:14:17 volumio-nuc sudo[2077]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Feb 5 14:31:57 UTC 2026"
VOLUMIO_VERSION="4.096"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="6759e875c98b942866984e844891d6c1"