-- Logs begin at Sat 2025-04-19 11:44:00 CEST, end at Sat 2025-04-19 11:47:51 CEST. --
Apr 19 11:46:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Apr 19 11:46:01 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:01 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:01 volumio go-librespot[1479]: go-librespot daemon starting...
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=debug msg="app state loaded"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02: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]"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02: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]"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02: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]"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=info msg="zeroconf server listening on port 35019"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=debug msg="obtained new client token: AADdmrqiZcbbw74fE2tRnPaMMV1GE1+KTbc37X/UnG645XTUdgQ3uBN3LpGhjpuLfEI6F7fI/RbGVNvEiKrViEYed0f91Awzida5AMBXOxcmy0Q1xBEBlSAT2xL1A829qmBLNO1N/Gxs8G6Nhyt+W64rJNdhjvgm1lK0jCZeur0H+2Azs2QRyDEtIVmYBwGsbCAO0Y2dZm9UFa0BROtENvZ2ryk4NzJJVa9hJVpreDTAysihZUbwRQDl/w=="
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=debug msg="completed challenge"
Apr 19 11:46:01 volumio go-librespot[1479]: time="2025-04-19T11:46:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:01 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:01 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:02 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 19 11:46:02 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 19 11:46:02 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 19 11:46:02 volumio volumio-remote-updater[569]: No test mode
Apr 19 11:46:02 volumio volumio-remote-updater[569]: No alpha test mode
Apr 19 11:46:02 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Apr 19 11:46:03 volumio volumio[994]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Apr 19 11:46:03 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 19 11:46:04 volumio volumio[994]: verbose: New Socket.io Connection to volumio from 192.168.1.191 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::volumioGetQueue
Apr 19 11:46:04 volumio volumio[994]: info: CoreStateMachine::getQueue
Apr 19 11:46:04 volumio volumio[994]: info: CorePlayQueue::getQueue
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid
Apr 19 11:46:04 volumio volumio[994]: info: CALLMETHOD: music_service inputs serialMonitorAction [object Object]
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: inputs , serialMonitorAction
Apr 19 11:46:04 volumio volumio[994]: info: Error : CoreCommandRouter::executeOnPlugin: No method [serialMonitorAction] in plugin inputs
Apr 19 11:46:04 volumio volumio[994]: info: CALLMETHOD: system_controller motivocontrol displaySelection [object Object]
Apr 19 11:46:04 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: motivocontrol , displaySelection
Apr 19 11:46:04 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:04 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Apr 19 11:46:05 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:05 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:05 volumio go-librespot[1548]: go-librespot daemon starting...
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=debug msg="app state loaded"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02: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]"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02: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]"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02: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]"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=info msg="zeroconf server listening on port 39995"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=debug msg="obtained new client token: AADTCEakna+hFuhGANlhSO0aYMSHZ3RgILLpQXiBVM4ahltzroXRIuv+TpIsT6aMUN/qx04bAnG4nBEGe8gVLwgmokLONIfx6IzND6XKNPJwEporAHQGSia6ctt8hejZH0qErndQfgihsC+Qk/veszkpENmMi7bNcR+Mgi9d5kRBpUadUHWHsHCPxhtlaqp8Q1F0KDPGt+QxOZHkkuW08gV6V6cu9mn7YXScIMuyRigO/hlBEEIVmeowBw=="
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=debug msg="completed challenge"
Apr 19 11:46:05 volumio go-librespot[1548]: time="2025-04-19T11:46:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:06 volumio volumio[994]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Apr 19 11:46:06 volumio volumio[994]: info: Completed starting MyVolumio Plugin
Apr 19 11:46:06 volumio volumio[994]: [Metrics] CommandRouter: 46s 813.24ms
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::volumiosetStartupVolume
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 19 11:46:06 volumio volumio[994]: info: VolumeController:: Setting startup Volume 10
Apr 19 11:46:06 volumio volumio[994]: info: VolumeController::SetAlsaVolume10
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::Close All Modals sent
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::Close All Modals sent
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:06 volumio volumio[994]: info: CoreStateMachine::pushState
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 19 11:46:06 volumio volumio[994]: info: CoreCommandRouter::volumioPushState
Apr 19 11:46:06 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10
Apr 19 11:46:06 volumio volumio[994]: SPOTIFY: SPOTIFY VOLUME 15
Apr 19 11:46:06 volumio volumio[994]: SPOTIFY: VOLUMIO VOLUME 10
Apr 19 11:46:06 volumio volumio[994]: SPOTIFY: DELTA VOLUME ENOUGH: true
Apr 19 11:46:06 volumio volumio[994]: info: Setting Spotify Volume from Volumio: 10
Apr 19 11:46:06 volumio volumio[994]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav
Apr 19 11:46:06 volumio volumio[994]: aplay: main:828: audio open error: Device or resource busy
Apr 19 11:46:07 volumio volumio[994]: info: CALLMETHOD: system_controller system enableSSH false
Apr 19 11:46:07 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , enableSSH
Apr 19 11:46:07 volumio sudo[1564]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop ssh.service
Apr 19 11:46:07 volumio sudo[1564]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:07 volumio systemd[1]: Stopping OpenBSD Secure Shell server...
Apr 19 11:46:07 volumio sshd[797]: Received signal 15; terminating.
Apr 19 11:46:07 volumio systemd[1]: ssh.service: Succeeded.
Apr 19 11:46:07 volumio systemd[1]: Stopped OpenBSD Secure Shell server.
Apr 19 11:46:07 volumio sudo[1564]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:07 volumio sudo[1566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable ssh.service
Apr 19 11:46:07 volumio sudo[1566]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:07 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Apr 19 11:46:07 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Apr 19 11:46:07 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Apr 19 11:46:07 volumio volumio[994]: info: Version has changed, forcing UI Reload
Apr 19 11:46:07 volumio volumio[994]: info: CoreCommandRouter::Reload Ui
Apr 19 11:46:07 volumio systemd[1]: Reloading.
Apr 19 11:46:07 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Apr 19 11:46:07 volumio volumio[994]: SPOTIFY: SETTING SPOTIFY VOLUME 10
Apr 19 11:46:07 volumio volumio[994]: info: Sending Spotify command with payload to local API: /player/volume
Apr 19 11:46:07 volumio volumio[994]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:08 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:08 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:08 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed.
Apr 19 11:46:08 volumio systemd[1]: Reloading.
Apr 19 11:46:08 volumio volumio[994]: info: CALLMETHOD: system_controller system enableSSH false
Apr 19 11:46:08 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , enableSSH
Apr 19 11:46:08 volumio sudo[1604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop ssh.service
Apr 19 11:46:08 volumio sudo[1604]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:08 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Apr 19 11:46:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Apr 19 11:46:09 volumio systemd[1]: Reloading.
Apr 19 11:46:09 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Apr 19 11:46:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Apr 19 11:46:10 volumio sudo[1566]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:10 volumio volumio[994]: info: disable SSH service success
Apr 19 11:46:10 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:10 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:10 volumio go-librespot[1627]: go-librespot daemon starting...
Apr 19 11:46:10 volumio sudo[1604]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:10 volumio sudo[1630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable ssh.service
Apr 19 11:46:10 volumio sudo[1630]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=debug msg="app state loaded"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:10 volumio systemd[1]: Reloading.
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02: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]"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02: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]"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02: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]"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=info msg="zeroconf server listening on port 33573"
Apr 19 11:46:10 volumio ntpd[795]: Soliciting pool server 191.96.11.19
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=debug msg="obtained new client token: AABJIABYjmTYL5RPKmCrtSuXPigk72JFzJBUcQhOu58RV1CCtciJUWEBFaR0nkMUV9WCMKZDxdd9A2RxVT8nF5pggAcULT81bt05b5Wg1L+KNc5VNGJ5IupolFZmMnUhXTEFHUOxyO0rPl5w9pEtgcT4Fb1H2Pr0GEHAY/zQcsFzXLcDyYO3w48bUKtIbGekMTYGJPOM7j0DLGQ3GVLDypiwK3P+i4DLlIgIx+Py1DjMQHWywNeIHe4ndw=="
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=debug msg="completed challenge"
Apr 19 11:46:10 volumio go-librespot[1627]: time="2025-04-19T11:46:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:10 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Apr 19 11:46:11 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:11 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:11 volumio systemd[1]: Reloading.
Apr 19 11:46:11 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Apr 19 11:46:12 volumio systemd[1]: Reloading.
Apr 19 11:46:12 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Apr 19 11:46:12 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:46:12 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:46:12 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:46:12 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:12 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:46:12 volumio volumio[994]: verbose: New Socket.io Connection to 192.168.1.224:3000 from 192.168.1.191 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6
Apr 19 11:46:12 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:12 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 19 11:46:12 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 19 11:46:13 volumio sudo[1630]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:13 volumio volumio[994]: info: disable SSH service success
Apr 19 11:46:13 volumio volumio[994]: info: BOOT COMPLETED
Apr 19 11:46:13 volumio ntpd[795]: Soliciting pool server 195.35.113.80
Apr 19 11:46:13 volumio ntpd[795]: Soliciting pool server 193.36.132.241
Apr 19 11:46:13 volumio ntpd[795]: Soliciting pool server 178.239.19.58
Apr 19 11:46:14 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:14 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Apr 19 11:46:14 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:14 volumio ntpd[795]: Soliciting pool server 129.250.35.250
Apr 19 11:46:14 volumio ntpd[795]: Soliciting pool server 185.71.60.123
Apr 19 11:46:14 volumio ntpd[795]: Soliciting pool server 178.239.19.63
Apr 19 11:46:14 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:14 volumio go-librespot[1707]: go-librespot daemon starting...
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02:00" level=debug msg="app state loaded"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02: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]"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02: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]"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02: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]"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02:00" level=info msg="zeroconf server listening on port 42377"
Apr 19 11:46:14 volumio go-librespot[1707]: time="2025-04-19T11:46:14+02:00" level=debug msg="obtained new client token: AAConoKp6pvuMvZcJ0p88QIak18QCZEqHpGm9Mk0RAqanvdIy/jiMBXOOQ10AQAXnvWhZMtqwE6pwoPHQNqFeRFRt050Ca41IHi3qPEtbF+zSBKzYWYPjRKfY1rUpOqKa3l45Er01rfXgRrfvXVg7/RJsP5TGMY/x/CFW0lclEh9kBtg9K235eJjsZJ780xG1n0dQG7m/A1Usg1/YtllTRSsPMVnSj5AKa14yCEll5Hu/jx9YzJXRjY="
Apr 19 11:46:15 volumio go-librespot[1707]: time="2025-04-19T11:46:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:15 volumio go-librespot[1707]: time="2025-04-19T11:46:15+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:15 volumio go-librespot[1707]: time="2025-04-19T11:46:15+02:00" level=debug msg="completed challenge"
Apr 19 11:46:15 volumio go-librespot[1707]: time="2025-04-19T11:46:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:15 volumio ntpd[795]: Soliciting pool server 162.159.200.123
Apr 19 11:46:15 volumio ntpd[795]: Soliciting pool server 149.210.142.45
Apr 19 11:46:15 volumio ntpd[795]: Soliciting pool server 5.255.124.190
Apr 19 11:46:16 volumio sudo[1720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 19 11:46:16 volumio sudo[1720]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:16 volumio sudo[1720]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:16 volumio sudo[1722]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 19 11:46:16 volumio sudo[1722]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:16 volumio sudo[1722]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:16 volumio ntpd[795]: Soliciting pool server 178.239.19.56
Apr 19 11:46:16 volumio ntpd[795]: Soliciting pool server 149.143.87.82
Apr 19 11:46:16 volumio ntpd[795]: Soliciting pool server 80.60.67.39
Apr 19 11:46:16 volumio volumio[994]: verbose: New Socket.io Connection to 192.168.1.224 from 192.168.1.191 UA: Mozilla/5.0 (Linux; Android 14; KB2003 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.38 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7
Apr 19 11:46:17 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:17 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:17 volumio sudo[1728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 19 11:46:17 volumio sudo[1728]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:17 volumio sudo[1728]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:17 volumio sudo[1730]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 19 11:46:17 volumio sudo[1730]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 19 11:46:17 volumio sudo[1730]: pam_unix(sudo:session): session closed for user root
Apr 19 11:46:17 volumio volumio[994]: verbose: New Socket.io Connection to 192.168.1.224 from 192.168.1.191 UA: Mozilla/5.0 (Linux; Android 14; KB2003 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.38 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 19 11:46:17 volumio ntpd[795]: Soliciting pool server 2a0d:5440::24
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 19 11:46:17 volumio volumio[994]: info: Received Get System Info
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:46:17 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:17 volumio volumio[994]: info: Listing playlists
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 19 11:46:17 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 19 11:46:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Apr 19 11:46:18 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:18 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:18 volumio go-librespot[1735]: go-librespot daemon starting...
Apr 19 11:46:18 volumio go-librespot[1735]: time="2025-04-19T11:46:18+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:18 volumio go-librespot[1735]: time="2025-04-19T11:46:18+02:00" level=debug msg="app state loaded"
Apr 19 11:46:18 volumio go-librespot[1735]: time="2025-04-19T11:46:18+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:18 volumio go-librespot[1735]: time="2025-04-19T11:46:18+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:19 volumio wpa_supplicant[909]: wlan0: CTRL-EVENT-DISCONNECTED bssid=ec:08:6b:2c:a1:6c reason=34
Apr 19 11:46:19 volumio dhcpcd[927]: wlan0: carrier lost
Apr 19 11:46:19 volumio wpa_supplicant[909]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Apr 19 11:46:19 volumio wpa_supplicant[909]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US
Apr 19 11:46:19 volumio avahi-daemon[565]: Withdrawing address record for 192.168.1.224 on wlan0.
Apr 19 11:46:19 volumio avahi-daemon[565]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.224.
Apr 19 11:46:19 volumio avahi-daemon[565]: Interface wlan0.IPv4 no longer relevant for mDNS.
Apr 19 11:46:19 volumio dhcpcd[927]: wlan0: deleting route to 192.168.1.0/24
Apr 19 11:46:19 volumio dhcpcd[927]: wlan0: deleting default route via 192.168.1.1
Apr 19 11:46:19 volumio volumio[994]: info: Discovery: A device disappeared from network
Apr 19 11:46:19 volumio volumio[994]: info: Discovery: Device volumio disappeared from network
Apr 19 11:46:20 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:20 volumio go-librespot[1735]: time="2025-04-19T11:46:20+02:00" level=debug msg="new websocket client"
Apr 19 11:46:20 volumio volumio[994]: info: Connection to go-librespot Websocket established
Apr 19 11:46:20 volumio wpa_supplicant[909]: wlan0: Trying to associate with SSID 'BPB'
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: carrier acquired
Apr 19 11:46:20 volumio wpa_supplicant[909]: wlan0: Associated with ec:08:6b:2c:a1:6c
Apr 19 11:46:20 volumio wpa_supplicant[909]: wlan0: CTRL-EVENT-CONNECTED - Connection to ec:08:6b:2c:a1:6c completed [id=0 id_str=]
Apr 19 11:46:20 volumio wpa_supplicant[909]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: IAID eb:f0:b5:ef
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: carrier lost
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: carrier acquired
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: IAID eb:f0:b5:ef
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: soliciting an IPv6 router
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: rebinding lease of 192.168.1.224
Apr 19 11:46:20 volumio dhcpcd[927]: wlan0: probing address 192.168.1.224/24
Apr 19 11:46:21 volumio ntpd[795]: Deleting interface #3 wlan0, 192.168.1.224#123, interface stats: received=22, sent=33, dropped=9, active_time=64 secs
Apr 19 11:46:21 volumio ntpd[795]: 80.60.67.39 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 178.239.19.56 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 149.143.87.82 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 5.255.124.190 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 149.210.142.45 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 162.159.200.123 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 178.239.19.63 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 185.71.60.123 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 129.250.35.250 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 178.239.19.58 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 193.36.132.241 local addr 192.168.1.224 ->
Apr 19 11:46:21 volumio ntpd[795]: 195.35.113.80 local addr 192.168.1.224 ->
Apr 19 11:46:22 volumio volumio[994]: info: Volumio Network Manager: Network status updated: 0
Apr 19 11:46:23 volumio volumio[994]: info: Getting Spotify volume
Apr 19 11:46:23 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Apr 19 11:46:23 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:23 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10
Apr 19 11:46:26 volumio dhcpcd[927]: wlan0: leased 192.168.1.224 for 43200 seconds
Apr 19 11:46:26 volumio avahi-daemon[565]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.224.
Apr 19 11:46:26 volumio dhcpcd[927]: wlan0: adding route to 192.168.1.0/24
Apr 19 11:46:26 volumio dhcpcd[927]: wlan0: adding default route via 192.168.1.1
Apr 19 11:46:26 volumio avahi-daemon[565]: New relevant interface wlan0.IPv4 for mDNS.
Apr 19 11:46:26 volumio avahi-daemon[565]: Registering new address record for 192.168.1.224 on wlan0.IPv4.
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 19 11:46:27 volumio volumio[994]: info: Discovery: adding 2c7d52a5-bb2d-469a-835f-5bda7a36805e
Apr 19 11:46:27 volumio volumio[994]: info: Discovery: Found device Volumio
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:27 volumio volumio[994]: info: Received Get System Info
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:46:27 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 19 11:46:27 volumio volumio[994]: info: Received Get System Info
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:46:27 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 19 11:46:27 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Apr 19 11:46:27 volumio ntpd[795]: Listen normally on 4 wlan0 192.168.1.224:123
Apr 19 11:46:27 volumio ntpd[795]: new interface(s) found: waking up resolver
Apr 19 11:46:28 volumio go-librespot[1735]: time="2025-04-19T11:46:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": net/http: TLS handshake timeout"
Apr 19 11:46:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:28 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: socket hang up
Apr 19 11:46:28 volumio volumio[994]: at connResetException (internal/errors.js:607:14)
Apr 19 11:46:28 volumio volumio[994]: at Socket.socketOnEnd (_http_client.js:493:23)
Apr 19 11:46:28 volumio volumio[994]: at Socket.emit (events.js:327:22)
Apr 19 11:46:28 volumio volumio[994]: at endReadableNT (internal/streams/readable.js:1327:12)
Apr 19 11:46:28 volumio volumio[994]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Apr 19 11:46:28 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3)
Apr 19 11:46:28 volumio volumio[994]: info: Connection to go-librespot Websocket closed
Apr 19 11:46:31 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Apr 19 11:46:31 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:31 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:31 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:31 volumio go-librespot[1851]: go-librespot daemon starting...
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02:00" level=debug msg="app state loaded"
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02: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]"
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02: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]"
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02: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]"
Apr 19 11:46:31 volumio go-librespot[1851]: time="2025-04-19T11:46:31+02:00" level=info msg="zeroconf server listening on port 34965"
Apr 19 11:46:32 volumio go-librespot[1851]: time="2025-04-19T11:46:32+02:00" level=debug msg="obtained new client token: AAA3uIGqgiaUQDRWBChMeG7adFsCvC4UAAf6fI+K4pfYJGl7j7AVObwxBrwKZqY9JlKzEGWaFtlRzkBkE/kJBcGMRc5NT6CSgVN6Qhm69SrqEa4ltW//a7L6DMWGL9Csun/dCu89o8xmH0dvaUunXD3hsvNBEpLCFx6hAoUJcQcIrK0O4lw0ERvHvJ5csi3lvzUiIZoHbD+BStG419WCNfiUv5Ek0Sz+sClWPBt7qPQLbCFbdCi5mIE="
Apr 19 11:46:32 volumio go-librespot[1851]: time="2025-04-19T11:46:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:32 volumio go-librespot[1851]: time="2025-04-19T11:46:32+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:32 volumio go-librespot[1851]: time="2025-04-19T11:46:32+02:00" level=debug msg="completed challenge"
Apr 19 11:46:32 volumio go-librespot[1851]: time="2025-04-19T11:46:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:32 volumio volumio[994]: info: Volumio Network Manager: Network status updated: 2
Apr 19 11:46:34 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:34 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:35 volumio ntpd[795]: receive: Unexpected origin timestamp 0xebadef7a.914ebad4 does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xebadef7b.cd503750
Apr 19 11:46:35 volumio ntpd[795]: receive: Unexpected origin timestamp 0xebadef7a.9150ed22 does not match aorg 0000000000.00000000 from server@185.71.60.123 xmt 0xebadef7b.cd5fa628
Apr 19 11:46:35 volumio ntpd[795]: receive: Unexpected origin timestamp 0xebadef7a.914bf2e8 does not match aorg 0000000000.00000000 from server@149.143.87.82 xmt 0xebadef7b.cd415e88
Apr 19 11:46:35 volumio ntpd[795]: receive: Unexpected origin timestamp 0xebadef7a.91532e81 does not match aorg 0000000000.00000000 from server@178.239.19.58 xmt 0xebadef7b.cdc3fbf4
Apr 19 11:46:35 volumio ntpd[795]: receive: Unexpected origin timestamp 0xebadef7a.91452106 does not match aorg 0000000000.00000000 from server@178.239.19.56 xmt 0xebadef7b.cdd7b0b8
Apr 19 11:46:35 volumio ntpd[795]: receive: Unexpected origin timestamp 0xebadef7a.91544f3d does not match aorg 0000000000.00000000 from server@193.36.132.241 xmt 0xebadef7b.cdd00dec
Apr 19 11:46:35 volumio ntpd[795]: receive: Unexpected origin timestamp 0xebadef7a.914fd948 does not match aorg 0000000000.00000000 from server@178.239.19.63 xmt 0xebadef7b.ce0e1da0
Apr 19 11:46:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Apr 19 11:46:36 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:36 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:36 volumio go-librespot[1881]: go-librespot daemon starting...
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02:00" level=debug msg="app state loaded"
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:36 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 19 11:46:36 volumio volumio[994]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Apr 19 11:46:36 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Apr 19 11:46:36 volumio volumio[994]: info: Received Get System Version
Apr 19 11:46:36 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 19 11:46:36 volumio volumio[994]: info: Received Get System Info
Apr 19 11:46:36 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:46:36 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:46:36 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:46:36 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:36 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02: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]"
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02: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]"
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02: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]"
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02:00" level=info msg="zeroconf server listening on port 36025"
Apr 19 11:46:36 volumio go-librespot[1881]: time="2025-04-19T11:46:36+02:00" level=debug msg="obtained new client token: AAAxZzuy7IJvrh3eMEygBS39N8Cmx/iPEtd8a3XiECMkFAij1Y//BqtvGQObew8wYr51fvlMZy5LMrGscBsWcdabx0b/7SXVopJ2UH+ydQn3OKKWnl9016fUt7Y066cmuuRa9AaM/92kTGrQsGmSNvk7T7dZwJnEasf4nAt0211p6LDWsCrQCp8S8UHQ0oDdTOI1Uz6gHdL1Cz+trt61a38LqF5LHGJ6YJwAfEj1xTjgdCFZPqhbzyFcrw=="
Apr 19 11:46:37 volumio go-librespot[1881]: time="2025-04-19T11:46:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:37 volumio go-librespot[1881]: time="2025-04-19T11:46:37+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:37 volumio go-librespot[1881]: time="2025-04-19T11:46:37+02:00" level=debug msg="completed challenge"
Apr 19 11:46:37 volumio go-librespot[1881]: time="2025-04-19T11:46:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:37 volumio volumio[994]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 19 11:46:38 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:38 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Apr 19 11:46:40 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:40 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:40 volumio go-librespot[1898]: go-librespot daemon starting...
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=debug msg="app state loaded"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02: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]"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02: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]"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02: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]"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=info msg="zeroconf server listening on port 43441"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=debug msg="obtained new client token: AABFDXH4e3TS1PwT48pZOPSx3U4FD+wQLduYakIeFf9tgqzNTFSTi+G3qyMIeueideUkKfdgAp+GsPvrjVwdOqndSJshIcdoa1/6RbL+TNMecNAd4HK6w9ry3ZaZnUgLPM7OV//cmJRX9Alu55mV/k5yHLK6YhKK1TKdPHBsOfYMvIbSEeNpRsmwsAab7Q1pka8t3YsFuvZZtQUO4kEw2dvNQ2nghpWzuI4hZx+VTDbChyduVW6zh+8LJA=="
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=debug msg="completed challenge"
Apr 19 11:46:40 volumio go-librespot[1898]: time="2025-04-19T11:46:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:41 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:41 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Apr 19 11:46:44 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:44 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:46:44 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:46:44 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:46:44 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:46:44 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:46:44 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:44 volumio go-librespot[1914]: go-librespot daemon starting...
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=debug msg="app state loaded"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02: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]"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02: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]"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02: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]"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=info msg="zeroconf server listening on port 44597"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=debug msg="obtained new client token: AAChCyx4hIakbqVFU0MqvNI/k4738JcLd39qAVOAHoWYjarG0Ttz0rJX3qyCJmlYnJcbyR9QDmWsPtgEejOpl8tpKuMURFFCLrqMFC/3TSL08eRQUyE50lMjV49ekAbhJC04cBSv5HOuQcQuhv8EcZXTa9UBXvMlMr3oCY2/eQ+EvkGUqEhMnLy9FpNVIUBxlBHJH+r2u3JCvC+qBzWgqoJpykYtcA/8aczmGeNNe+/4RU4lgLTPK99kCA=="
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=debug msg="completed challenge"
Apr 19 11:46:44 volumio go-librespot[1914]: time="2025-04-19T11:46:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:44 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:44 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:46 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 19 11:46:46 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 19 11:46:47 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:47 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Apr 19 11:46:47 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:47 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:47 volumio go-librespot[1942]: go-librespot daemon starting...
Apr 19 11:46:47 volumio go-librespot[1942]: time="2025-04-19T11:46:47+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:47 volumio go-librespot[1942]: time="2025-04-19T11:46:47+02:00" level=debug msg="app state loaded"
Apr 19 11:46:47 volumio go-librespot[1942]: time="2025-04-19T11:46:47+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:47 volumio go-librespot[1942]: time="2025-04-19T11:46:47+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02: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]"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02: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]"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02: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]"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02:00" level=info msg="zeroconf server listening on port 42559"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02:00" level=debug msg="obtained new client token: AACx6qBX+qycDUcG0lS5KRZlhDe8Zc/NDSB6YiR0Ky2Z43a+SbczGzWfxfse1CeOrOu4UBrGPeY6s8Z8K53gdAJh7tMM9myz0to/be1T5uIRKv4H3ZFehj3/Loa1yjQB+OW4Q14lerL+bk8eCW9owe3e5Y9eGfu1/qa0YNyPKYIZ7B5eLSryGuKUjKX6GiqTAU1kCp9LhHGav10gpqwbM5xZXVDiBu38PZ8Z/IFRQx/q4mHxRxH6QXI="
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02:00" level=debug msg="completed challenge"
Apr 19 11:46:48 volumio go-librespot[1942]: time="2025-04-19T11:46:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:50 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:50 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:51 volumio volumio[994]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/ytcr/volumio/buster/armhf
Apr 19 11:46:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Apr 19 11:46:51 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:51 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:51 volumio go-librespot[1963]: go-librespot daemon starting...
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02:00" level=debug msg="app state loaded"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02: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]"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02: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]"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02: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]"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02:00" level=info msg="zeroconf server listening on port 40175"
Apr 19 11:46:51 volumio go-librespot[1963]: time="2025-04-19T11:46:51+02:00" level=debug msg="obtained new client token: AADteLeeipZqw1wBnQ7RzD7MP8EWk/Hc3pZhM8UUnNPlqTs4U8rKREZwiGdMMRYnaIzSYMx6PtVA7cmzMplfZkeRZ9U9zh9v2ZdNLtXvpB+gRtXiN+DHWY4hRUV1GXu3h9DhhUyy5Y2tKFIB1k9Hys0RCr1ntmAkziaM/Z4/7lqBq0gHyUl27S0HlmaZsqqITqnkirqiH1pBGUmAMO/1cVARCip/MhtZrABqUmuBRogvaE25/DEIp3OjqQ=="
Apr 19 11:46:52 volumio go-librespot[1963]: time="2025-04-19T11:46:52+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:52 volumio go-librespot[1963]: time="2025-04-19T11:46:52+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:52 volumio go-librespot[1963]: time="2025-04-19T11:46:52+02:00" level=debug msg="completed challenge"
Apr 19 11:46:52 volumio go-librespot[1963]: time="2025-04-19T11:46:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:53 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:53 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Apr 19 11:46:55 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:55 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:55 volumio go-librespot[1994]: go-librespot daemon starting...
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02:00" level=debug msg="app state loaded"
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02: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]"
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02: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]"
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02: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]"
Apr 19 11:46:55 volumio go-librespot[1994]: time="2025-04-19T11:46:55+02:00" level=info msg="zeroconf server listening on port 45703"
Apr 19 11:46:56 volumio go-librespot[1994]: time="2025-04-19T11:46:56+02:00" level=debug msg="obtained new client token: AAACT988StjJJC3yhrCYre/byo0VDCJkmKQIu9ZMy6vHeSnknE2geykcIyeSKkA7dHw2s2w4lMm+e9HIE9DDqJA+yETkwBrwfuySIHm1Y8Zd7CThMBe0oUBS8MbL18VCdbsUfockdRYVLnEZkAA6wO5WqDUql/QSw3uSzb6IJ/izjD+MIdSjb5dLE6FjPnefLo8gMFrLfMmexdxnM0U3Roy0N2u2RcJqBM4Ri6nxMI8JzW79Fjk0SLI="
Apr 19 11:46:56 volumio go-librespot[1994]: time="2025-04-19T11:46:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:46:56 volumio go-librespot[1994]: time="2025-04-19T11:46:56+02:00" level=debug msg="completed keyexchange"
Apr 19 11:46:56 volumio go-librespot[1994]: time="2025-04-19T11:46:56+02:00" level=debug msg="completed challenge"
Apr 19 11:46:56 volumio go-librespot[1994]: time="2025-04-19T11:46:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:46:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:46:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:46:56 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:56 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:46:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:46:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Apr 19 11:46:59 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:46:59 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:46:59 volumio go-librespot[2011]: go-librespot daemon starting...
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02:00" level=debug msg="app state loaded"
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02:00" level=debug msg="stored credentials not found"
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:46:59 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02:00" level=debug msg="new websocket client"
Apr 19 11:46:59 volumio volumio[994]: info: Connection to go-librespot Websocket established
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02: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]"
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02: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]"
Apr 19 11:46:59 volumio go-librespot[2011]: time="2025-04-19T11:46:59+02: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]"
Apr 19 11:47:00 volumio go-librespot[2011]: time="2025-04-19T11:47:00+02:00" level=info msg="zeroconf server listening on port 42361"
Apr 19 11:47:00 volumio go-librespot[2011]: time="2025-04-19T11:47:00+02:00" level=debug msg="obtained new client token: AABolTXpZGEuyzQKm+IVdp1+6szcuxp9kZC8e7fvGXdtuEo2wSnkqn1VnrjtgRwZ0JiNz0r/Y8htVGXjDHDe2YBK7uze9DwePw7qtYZvSluhjXMfsBCXx6Iokyc3pf417UA/x1ysraD4BrwNI4bIcEanCaA5kHytmFPpfTviZZeS+lZj0kdVc7aLbO2ImociwuaDvTc5UfE1hqiywprdh6Yp1LD8tF+Mt+PZ1MS8yk+tLyox/ZgPg2A="
Apr 19 11:47:00 volumio go-librespot[2011]: time="2025-04-19T11:47:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:00 volumio go-librespot[2011]: time="2025-04-19T11:47:00+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:00 volumio go-librespot[2011]: time="2025-04-19T11:47:00+02:00" level=debug msg="completed challenge"
Apr 19 11:47:00 volumio go-librespot[2011]: time="2025-04-19T11:47:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:00 volumio volumio[994]: info: Connection to go-librespot Websocket closed
Apr 19 11:47:02 volumio volumio[994]: info: Getting Spotify volume
Apr 19 11:47:02 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:02 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 19 11:47:02 volumio volumio[994]: (node:994) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 4)
Apr 19 11:47:02 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Apr 19 11:47:02 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:47:02 volumio volumio[994]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10
Apr 19 11:47:03 volumio volumio[994]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/ytcr/volumio/buster/armhf
Apr 19 11:47:03 volumio volumio[994]: info: [yt-cast-receiver] Player.reset()
Apr 19 11:47:03 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:47:03 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:03 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21.
Apr 19 11:47:03 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:03 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:03 volumio go-librespot[2029]: go-librespot daemon starting...
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02:00" level=debug msg="app state loaded"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02: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]"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02: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]"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02: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]"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02:00" level=info msg="zeroconf server listening on port 34083"
Apr 19 11:47:03 volumio go-librespot[2029]: time="2025-04-19T11:47:03+02:00" level=debug msg="obtained new client token: AADg2XHNso6XcfUOMMLeWI6FyjDxXfzNT9pe1zBIymhRmmRa6JaK73d5z8xbSIwoV8TLJ/g6TbPplmB0loEH877+puJJWSCt11Cuf99NJlPmFe3sRfEBGHh+G9+9eYuvLJUBkQAbtj2UnIZILbeYtjEXm/xPkEmsTEvWcAoc6ztNRyTjkZNeLfp8QPmctUvB7qX3C7lmXuBnzFYJuNuwb/XkT+duI8+Eunyclxz2ry/FBDpS1+jVWic0pg=="
Apr 19 11:47:04 volumio go-librespot[2029]: time="2025-04-19T11:47:04+02: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"
Apr 19 11:47:04 volumio go-librespot[2029]: time="2025-04-19T11:47:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Apr 19 11:47:04 volumio go-librespot[2029]: time="2025-04-19T11:47:04+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:04 volumio go-librespot[2029]: time="2025-04-19T11:47:04+02:00" level=debug msg="completed challenge"
Apr 19 11:47:04 volumio go-librespot[2029]: time="2025-04-19T11:47:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:06 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:06 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22.
Apr 19 11:47:07 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:07 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:07 volumio go-librespot[2095]: go-librespot daemon starting...
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=debug msg="app state loaded"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02: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]"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02: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]"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02: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]"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=info msg="zeroconf server listening on port 40157"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=debug msg="obtained new client token: AAAqCz/khGBMI3IkVZOQFNUru1TUzpNk65ozVMzUJRE5T8Cl25gFqBolOVR+H+gOJGnXQMwBS02UZnPB4jlYGR+04txAdVu18xrGDiBTL6/HdMIdtgMrmzSTJs/CGnLyTvkCsulapUun0tc6sERM+/fv8KllP7JhDJnbVxMoBcw55zLN1047c2pJezkexbGMh4Jx1dUAPkeBF922ODXJ/Sm+zJp0rOFCET5YbAXtPVQsrB0DRWRGTKiUaw=="
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=debug msg="completed challenge"
Apr 19 11:47:07 volumio go-librespot[2095]: time="2025-04-19T11:47:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:09 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:09 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23.
Apr 19 11:47:11 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:11 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:11 volumio go-librespot[2114]: go-librespot daemon starting...
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=debug msg="app state loaded"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02: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]"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02: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]"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02: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]"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=info msg="zeroconf server listening on port 35223"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=debug msg="obtained new client token: AAA9zbwPuHBhTKjDotAhMX1UztA9BNlsKyvt9e/xzYE1LRQ6hei609b1X0BOq0E1Qr2BR//9It7Jx7IAsfq5eeIEtAMSG5TdZa57x99Mc2ceAgIIz8lOsGn5Kz+6b1+pilXIXkU0YQ2yXy6D6shNC0FE2B+/V93x9ba/tb+fwWITKupGdfuaezl3Ns/J0Yx6cJIGhuF1LVt/lXkGMhCiyNC1Wf7UZUOYlVRfHNhLnSkq1NYYX0F96nwAig=="
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=debug msg="completed challenge"
Apr 19 11:47:11 volumio go-librespot[2114]: time="2025-04-19T11:47:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:12 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:12 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:14 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:47:14 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:47:14 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:47:14 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:47:14 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:47:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24.
Apr 19 11:47:14 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:14 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:14 volumio go-librespot[2144]: go-librespot daemon starting...
Apr 19 11:47:14 volumio go-librespot[2144]: time="2025-04-19T11:47:14+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:14 volumio go-librespot[2144]: time="2025-04-19T11:47:14+02:00" level=debug msg="app state loaded"
Apr 19 11:47:14 volumio go-librespot[2144]: time="2025-04-19T11:47:14+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:14 volumio go-librespot[2144]: time="2025-04-19T11:47:14+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02: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]"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02: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]"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02: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]"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02:00" level=info msg="zeroconf server listening on port 46155"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02:00" level=debug msg="obtained new client token: AADtgs/H+PiW/6hKRuEZwYC3yYDWhuF2bXzKrMU0cfg1W0s78IsHmNahc0FEjWR/Ak2khWLkcfd42mbERxLBIkv4NH79RcskLsSnAIhQc+EsY7MmRBNqJpmF/xlvFZwAFH6u/RAE87bcBsUscScziDbhiMSPo789+Icppay/FMm3JLy7dsX1+69bhDno8k313ryKBzVrDwj8BJ5Qcba9yfz7UAyoze2T3WO/p1LrLeN/rKgMuu8XgoU="
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02:00" level=debug msg="completed challenge"
Apr 19 11:47:15 volumio go-librespot[2144]: time="2025-04-19T11:47:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:15 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:15 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:15 volumio ntpd[795]: Soliciting pool server 45.159.204.28
Apr 19 11:47:16 volumio ntpd[795]: Soliciting pool server 94.198.159.15
Apr 19 11:47:17 volumio ntpd[795]: Soliciting pool server 84.82.15.107
Apr 19 11:47:18 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:18 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25.
Apr 19 11:47:18 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:18 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:18 volumio go-librespot[2158]: go-librespot daemon starting...
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02:00" level=debug msg="app state loaded"
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:18 volumio ntpd[795]: Soliciting pool server 191.96.11.19
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02: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]"
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02: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]"
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02: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]"
Apr 19 11:47:18 volumio go-librespot[2158]: time="2025-04-19T11:47:18+02:00" level=info msg="zeroconf server listening on port 38197"
Apr 19 11:47:19 volumio go-librespot[2158]: time="2025-04-19T11:47:19+02:00" level=debug msg="obtained new client token: AADjnRuCw9qEt3yy4Eagv+aosJDasPPn8cQZy8zcmE7eCCd9u1VfwM4Pke1ApXVNICnSKaIHl5u4/+X+okUR5SLKFhj1g9bZaUxTL1TtrDh6j227sRqSzDhqjrLhtk9XXb3K629WFnB1WHzYLyXTkihnFIJxk9e2mgQxq078Bc2QRo5NP705uFbBAc6laV0f/NkKeW3GOTlop73Vluo+LLrCJey0K9aqMx1PwJOC2eshXiTe0DAnjCE="
Apr 19 11:47:19 volumio go-librespot[2158]: time="2025-04-19T11:47:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:19 volumio go-librespot[2158]: time="2025-04-19T11:47:19+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:19 volumio go-librespot[2158]: time="2025-04-19T11:47:19+02:00" level=debug msg="completed challenge"
Apr 19 11:47:19 volumio go-librespot[2158]: time="2025-04-19T11:47:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:21 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:21 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26.
Apr 19 11:47:22 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:22 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:22 volumio go-librespot[2174]: go-librespot daemon starting...
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=debug msg="app state loaded"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02: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]"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02: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]"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02: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]"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=info msg="zeroconf server listening on port 33201"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=debug msg="obtained new client token: AAD592WhiCTJ7RAm4sCXffu1rjDbaf5BFVNcokAd5qEgP/tdm6XzkixW39WJmd3tn0Sx7eloJ5Hd2z+MW6NWoQ9Na/aQ17+W05TPRRPiCoSTFWSJBQvveY2TTMdxL7apx3+u9fz/Srjn1O5saNp8w+K1DNWkIYZmgn6uct0FG8ZxjcFYS2Ax/xR3ciDccuXW8mAMuCikr/w6HrIDvBxsBGRjRBvlkwTIGImjz06yOBaBlg922QHm/jBJ/A=="
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=debug msg="completed challenge"
Apr 19 11:47:22 volumio go-librespot[2174]: time="2025-04-19T11:47:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:24 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:24 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:25 volumio volumio[994]: info: Check plugin dependencies
Apr 19 11:47:25 volumio ntpd[795]: Soliciting pool server 2a07:e042:1:260::1
Apr 19 11:47:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27.
Apr 19 11:47:26 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:26 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:26 volumio go-librespot[2204]: go-librespot daemon starting...
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=debug msg="app state loaded"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02: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]"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02: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]"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02: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]"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=info msg="zeroconf server listening on port 44929"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=debug msg="obtained new client token: AAB3yzhCLVsOI6p9wTVWNVbAcSSggB/jWCFM4QFq6EEN/zelMI24lbD1l3BFCDk1DjVBukV7qHSzdHRCtglaYZj6FhDbx8gWSzOx2Dblkexi0pXgS8ULoTyxKkHyC6OZluPsm7suWYTAf2pmsrOkQFI7IR70IOxe3KQCvATsmSDtl2KtYCRwuEdrsNbN2yxSz3L37RrXOgVlZ31xndr2qJTcJYCdUZui8a3NRNJVIDPOgIeSe4Htg2gAng=="
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02: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"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=debug msg="completed challenge"
Apr 19 11:47:26 volumio go-librespot[2204]: time="2025-04-19T11:47:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28.
Apr 19 11:47:29 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:29 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:29 volumio go-librespot[2212]: go-librespot daemon starting...
Apr 19 11:47:29 volumio go-librespot[2212]: time="2025-04-19T11:47:29+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:29 volumio go-librespot[2212]: time="2025-04-19T11:47:29+02:00" level=debug msg="app state loaded"
Apr 19 11:47:29 volumio go-librespot[2212]: time="2025-04-19T11:47:29+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:29 volumio go-librespot[2212]: time="2025-04-19T11:47:29+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02: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]"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02: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]"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02: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]"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02:00" level=info msg="zeroconf server listening on port 41301"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02:00" level=debug msg="obtained new client token: AAB4V5kDJ/Nkqaq71/mHAHqAiAy9JNccUT7jWh81aktimRJEwkiQscLbLfZUJNNqifgZATW/E6gaTN6FqIDH75FMRJxY0SZfHBr//DaLD1c+9vO+cYjUw0FPkoqSlRgcii+VWCZ+vgdzd2ieoISqNHEvX+rb01yRAReCF8a4zjF4qwhStkhjLBXeQUIxgqsxIjUHvvClzydgOn+PFtC41ZmXcGEguDw8qMkGzC/bdnhvmPn9OHxoip8="
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02:00" level=debug msg="completed challenge"
Apr 19 11:47:30 volumio go-librespot[2212]: time="2025-04-19T11:47:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29.
Apr 19 11:47:33 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:33 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:33 volumio go-librespot[2224]: go-librespot daemon starting...
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02:00" level=debug msg="app state loaded"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02: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]"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02: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]"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02: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]"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02:00" level=info msg="zeroconf server listening on port 44183"
Apr 19 11:47:33 volumio go-librespot[2224]: time="2025-04-19T11:47:33+02:00" level=debug msg="obtained new client token: AAB3VzfVDn+EiY7i10lvJ/Fq9FyseQAKwExiiPzBTAeT9Y+2o5OE0f6jL7O1xVGN4G/743ihaGcx+7OvAIxNCQO67S1qsXEaT5KvbvDWS4q1m5DqoMiD/rHgMY7Xh0JnRU5rQOnD56pLFO2gB7bIngnJuEedK/CcrRHRWP7G2+up+oUVQjgxRA9OzchHbRKKWllUWXEfVbx56VfShS+oHPoOtjHHiulWTBe5gukLkknqlVA+d3MF4NDvJQ=="
Apr 19 11:47:34 volumio go-librespot[2224]: time="2025-04-19T11:47:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:34 volumio go-librespot[2224]: time="2025-04-19T11:47:34+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:34 volumio go-librespot[2224]: time="2025-04-19T11:47:34+02:00" level=debug msg="completed challenge"
Apr 19 11:47:34 volumio go-librespot[2224]: time="2025-04-19T11:47:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30.
Apr 19 11:47:37 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:37 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:37 volumio go-librespot[2246]: go-librespot daemon starting...
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=debug msg="app state loaded"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02: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]"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02: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]"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02: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]"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=info msg="zeroconf server listening on port 43355"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=debug msg="obtained new client token: AABln0523YUu9mNZ/16U/IyxyIdpu4oJZ1x6euDyYr6YYZnm8rzIzTERdu12M7cdPFzi08aPv7KKUbz4UkduKcPwgez03w1FPBcqjAYgRX5f5QEhk7loNgyCEmkRmiAB5C73yZJU3mQ8k93P7WooBgttS9EJ/FqPd8wWRWKp5bD3jTD9CQG3VlPedDY+E6b4XxntRpb08c4QWV08Yz0yQqTQ/zQuBjhL0lKE7datA0oF4pcigPo2WLM5Tw=="
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=debug msg="completed challenge"
Apr 19 11:47:37 volumio go-librespot[2246]: time="2025-04-19T11:47:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 19 11:47:40 volumio volumio[994]: info: Rename folder
Apr 19 11:47:40 volumio volumio[994]: info: Initializing connection to go-librespot Websocket
Apr 19 11:47:40 volumio volumio[994]: info: Move to category
Apr 19 11:47:40 volumio volumio[994]: info: Folder /tmp/downloaded_plugin.zip removed
Apr 19 11:47:40 volumio volumio[994]: Upnp client error: Error: This socket has been ended by the other party
Apr 19 11:47:40 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 19 11:47:40 volumio volumio[994]: verbose: New Socket.io Connection to 192.168.1.224:3000 from 192.168.1.191 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5
Apr 19 11:47:40 volumio volumio[994]: verbose: New Socket.io Connection to 192.168.1.224 from 192.168.1.191 UA: Mozilla/5.0 (Linux; Android 14; KB2003 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.38 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
Apr 19 11:47:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:47:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:47:40 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:47:40 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:47:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:47:40 volumio volumio[994]: Upnp client error: Error: This socket has been ended by the other party
Apr 19 11:47:40 volumio volumio[994]: Upnp client error: Error: This socket has been ended by the other party
Apr 19 11:47:40 volumio volumio[994]: Upnp client error: Error: This socket has been ended by the other party
Apr 19 11:47:40 volumio volumio[994]: Upnp client error: Error: This socket has been ended by the other party
Apr 19 11:47:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Apr 19 11:47:41 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:41 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:41 volumio go-librespot[2258]: go-librespot daemon starting...
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=debug msg="app state loaded"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02: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]"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02: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]"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02: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]"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=info msg="zeroconf server listening on port 46455"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=debug msg="obtained new client token: AAA5wr2dk4Flot2dth4Ej4MbavPlin0RWFIu66BNGHBmjuB667a00q+WCCVpV0224PGjMojnkgvScvWjFqEhWwfCUfikziL9TpkSdyANvy4nl9S5wO6rkcxYGUQPX4L+anLTbaziYKz6hkyXy3fjSbKyOY8MBDO7WD7cvUPxqZpFr7kYdtVdFfsp+YJJMu4XB2K2Wx68D19yYKi2mF+KmjPRI4Njbwa5442//rkXW9DdNjyJe6+lqmhQyw=="
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02: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"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=debug msg="completed challenge"
Apr 19 11:47:41 volumio go-librespot[2258]: time="2025-04-19T11:47:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:42 volumio volumio[994]: verbose: New Socket.io Connection to 192.168.1.224 from 192.168.1.191 UA: Mozilla/5.0 (Linux; Android 14; KB2003 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.38 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 19 11:47:42 volumio volumio[994]: info: Received Get System Info
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 19 11:47:42 volumio volumio[994]: info: Discovery: Getting this device information
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 19 11:47:42 volumio volumio[994]: info: CoreCommandRouter::volumioGetState
Apr 19 11:47:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Apr 19 11:47:45 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:45 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:45 volumio go-librespot[2282]: go-librespot daemon starting...
Apr 19 11:47:45 volumio go-librespot[2282]: time="2025-04-19T11:47:45+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:45 volumio go-librespot[2282]: time="2025-04-19T11:47:45+02:00" level=debug msg="app state loaded"
Apr 19 11:47:45 volumio go-librespot[2282]: time="2025-04-19T11:47:45+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:45 volumio go-librespot[2282]: time="2025-04-19T11:47:45+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02: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]"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02: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]"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02: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]"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02:00" level=info msg="zeroconf server listening on port 38991"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02:00" level=debug msg="obtained new client token: AACVmEhLxKDmX2iyGKbnH/NzL2NV8dlK6Sxh/MmKem/N7WOPTlYNduCTGyYZM3NIvkkgsl6+OVtIfVemjdcq294rO9UxQ7UXiIiXj7ad5DqXhBU1gqiAAzGR5n5NIcCBiKSy6G2lT6IzmStnLyuyYQses35lwgkc6lHZCZrYZb5gF2lx63B7lbP/UR6ohHIukOZnWHQscNLRlAa/JT982CnLyLDeaR/p1CXY7Fgv+93AZf2a/ems0St+dg=="
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02:00" level=debug msg="completed challenge"
Apr 19 11:47:47 volumio go-librespot[2282]: time="2025-04-19T11:47:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 19 11:47:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Apr 19 11:47:51 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 19 11:47:51 volumio systemd[1]: Started go-librespot Daemon.
Apr 19 11:47:51 volumio go-librespot[2293]: go-librespot daemon starting...
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=info msg="running go-librespot 0.2.0"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=debug msg="app state loaded"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=debug msg="stored credentials not found"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 19 11:47:51 volumio volumio[994]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 19 11:47:51 volumio volumio[994]: TypeError: Cannot read property 'plugin_type' of undefined
Apr 19 11:47:51 volumio volumio[994]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1644:56)
Apr 19 11:47:51 volumio volumio[994]: at CoreCommandRouter.getInstalledPlugins (/volumio/app/index.js:1540:29)
Apr 19 11:47:51 volumio volumio[994]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1342:45)
Apr 19 11:47:51 volumio volumio[994]: at Socket.emit (events.js:315:20)
Apr 19 11:47:51 volumio volumio[994]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
Apr 19 11:47:51 volumio volumio[994]: at processTicksAndRejections (internal/process/task_queues.js:75:11)
Apr 19 11:47:51 volumio volumio[994]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02: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]"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02: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]"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02: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]"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=info msg="zeroconf server listening on port 44061"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=debug msg="obtained new client token: AAAWpA0kPl6KB6X5crdU+S9lhyeS94dMYc2aSk3doF7bQzC58hedOPmRSanab/jwG3zQcxzsDH956P7YYkr3mb4fI1UdtM9o5ZEhEVHQ7Esznng+NYJDXdytUDFoZzBcNGk+R1KKYDF96O56o5QDq413yEBc//mfmkyL7gdIpOUWkLX26+anc3rRk6ZOrLNreVLCkx13FkMMIGf/OR9O7bGRsa03BPWSX5x1LH5VWvCirqz+4r3Qxx7usw=="
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=debug msg="completed keyexchange"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=debug msg="completed challenge"
Apr 19 11:47:51 volumio go-librespot[2293]: time="2025-04-19T11:47:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Apr 19 11:47:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 19 11:47:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 19 11:47:51 volumio sudo[2310]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-19 11:46
Apr 19 11:47:51 volumio sudo[2310]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
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="147953990fca4aa103a8f90538ef56fb0454638c"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST"
VOLUMIO_VERSION="3.799"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"