Feb 25 13:22:25 volumio sudo[24425]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 25 13:22:25 volumio sudo[24423]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 25 13:22:25 volumio sudo[24425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 25 13:22:25 volumio sudo[24423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 25 13:22:25 volumio sudo[24423]: pam_unix(sudo:session): session closed for user root
Feb 25 13:22:25 volumio sudo[24425]: pam_unix(sudo:session): session closed for user root
Feb 25 13:22:25 volumio volumio[1007]: verbose: New Socket.io Connection to 192.168.1.73 from 192.168.1.64 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Edg/145.0.0.0 Engine version: 3 Transport: polling Total Clients: 5
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetVisibleSources
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetQueue
Feb 25 13:22:33 volumio volumio[1007]: info: CoreStateMachine::getQueue
Feb 25 13:22:33 volumio volumio[1007]: info: CorePlayQueue::getQueue
Feb 25 13:22:33 volumio volumio[1007]: info: Listing playlists
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Feb 25 13:22:33 volumio volumio[1007]: info: Received Get System Info
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 25 13:22:33 volumio volumio[1007]: info: Discovery: Getting this device information
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 25 13:22:33 volumio volumio[1007]: info: Received Get System Info
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 25 13:22:33 volumio volumio[1007]: info: Discovery: Getting this device information
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 25 13:22:33 volumio volumio[1007]: info: Received Get System Info
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 25 13:22:33 volumio volumio[1007]: info: Discovery: Getting this device information
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState
Feb 25 13:22:33 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Feb 25 13:22:35 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Feb 25 13:22:35 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Feb 25 13:22:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 25 13:22:38 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Feb 25 13:22:42 volumio go-librespot[1390]: time="2026-02-25T13:22:42Z" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF"
Feb 25 13:22:42 volumio volumio[1007]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify
Feb 25 13:22:42 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 25 13:22:42 volumio volumio[1007]: Cannot find translation for source YouTube Music
Feb 25 13:22:42 volumio volumio[1007]: info: Disabling plugin spop
Feb 25 13:22:42 volumio volumio[1007]: info: Done.
Feb 25 13:22:42 volumio volumio[1007]: info: Connection to go-librespot Websocket closed
Feb 25 13:22:42 volumio sudo[24450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service
Feb 25 13:22:42 volumio sudo[24450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 25 13:22:42 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 25 13:22:42 volumio systemd[1]: go-librespot-daemon.service: Killing process 19016 (go-librespot) with signal SIGKILL.
Feb 25 13:22:42 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 25 13:22:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:42 volumio systemd[1]: go-librespot-daemon.service: Consumed 1h 13min 2.113s CPU time.
Feb 25 13:22:42 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:22:42 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:22:42 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:22:42 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:22:42 volumio sudo[24450]: pam_unix(sudo:session): session closed for user root
Feb 25 13:22:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 25 13:22:43 volumio volumio[1007]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Feb 25 13:22:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Feb 25 13:22:43 volumio volumio[1007]: info: Received Get System Version
Feb 25 13:22:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 25 13:22:43 volumio volumio[1007]: info: Received Get System Info
Feb 25 13:22:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 25 13:22:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 25 13:22:43 volumio volumio[1007]: info: Discovery: Getting this device information
Feb 25 13:22:43 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState
Feb 25 13:22:43 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 25 13:22:45 volumio volumio[1007]: info: Enabling plugin spop
Feb 25 13:22:45 volumio volumio[1007]: info: Loading plugin "spop"...
Feb 25 13:22:45 volumio volumio[1007]: info: PLUGIN START: spop
Feb 25 13:22:45 volumio volumio[1007]: info: Creating Spotify config file
Feb 25 13:22:45 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 25 13:22:45 volumio volumio[1007]: info: Done.
Feb 25 13:22:45 volumio volumio[1007]: info: Spotify config file written
Feb 25 13:22:45 volumio volumio[1007]: info: No need to fix Spotify hosts
Feb 25 13:22:45 volumio sudo[24467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 25 13:22:45 volumio sudo[24467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 25 13:22:45 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:22:45 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:22:45 volumio volumio[1007]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 25 13:22:45 volumio volumio[1007]: SPOTIFY: BQDg4J4E8DEvRKbDFGvDKhXBMQhVZQuyE25uK6Dn-9ZNoFsXIDpZdAFwORZsGEbGl3ZXaabbCyzLa7HGwwFO6MDDhbjascqCALk1amQxEjJYWTO3GAKyu5jdaWDmROWJ3eqFC4Qzcuk9QOqP97Wv4XIl1rVS-7zljQcp4ws78DpI1Q7h3B8hocbLO5cD04AUQe-hdZH7Yk8EgbxaFxbWEUNjd3iHWPI7v-UeH52k717l3mPcXMoe1CjRoyFZfjw_9bqmMjNBjyf-RUB7Qi_7q2jy9_ou8nyPleMo
Feb 25 13:22:45 volumio volumio[1007]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 25 13:22:45 volumio volumio[1007]: info: New Spotify access token = BQDg4J4E8DEvRKbDFGvDKhXBMQhVZQuyE25uK6Dn-9ZNoFsXIDpZdAFwORZsGEbGl3ZXaabbCyzLa7HGwwFO6MDDhbjascqCALk1amQxEjJYWTO3GAKyu5jdaWDmROWJ3eqFC4Qzcuk9QOqP97Wv4XIl1rVS-7zljQcp4ws78DpI1Q7h3B8hocbLO5cD04AUQe-hdZH7Yk8EgbxaFxbWEUNjd3iHWPI7v-UeH52k717l3mPcXMoe1CjRoyFZfjw_9bqmMjNBjyf-RUB7Qi_7q2jy9_ou8nyPleMo
Feb 25 13:22:45 volumio volumio[1007]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 25 13:22:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:45 volumio go-librespot[24469]: go-librespot daemon starting...
Feb 25 13:22:45 volumio sudo[24467]: pam_unix(sudo:session): session closed for user root
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=debug msg="app state loaded"
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:22:45 volumio volumio[1007]: SPOTIFY: User informations: {"country":"GB","display_name":"1123700120","email":"jason.duncalf@btinternet.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1123700120"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/1123700120","id":"1123700120","images":[],"product":"premium","type":"user","uri":"spotify:user:1123700120"}
Feb 25 13:22:45 volumio volumio[1007]: info: Spotify Successfully logged in
Feb 25 13:22:45 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 25 13:22:45 volumio volumio[1007]: info: [1772025765720] CoreMusicLibrary::Adding element Spotify
Feb 25 13:22:45 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 25 13:22:45 volumio volumio[1007]: Cannot find translation for source YouTube Music
Feb 25 13:22:45 volumio volumio[1007]: Cannot find translation for source Spotify
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=info msg="zeroconf server listening on port 40935"
Feb 25 13:22:45 volumio go-librespot[24470]: time="2026-02-25T13:22:45Z" level=debug msg="obtained new client token: AAA3xIJkIsqtkuxy8WY/Rx5hlMXEZmiqary64kcYmXBmEjPJhBjBcITu+pbxjxBqBoY3zFBQ52cBGzfYKesH/NC8Kogps7ROB0YtklqjVSESy8Voa65NOCOjCLH7Fd2/ph+rO2EmEyo2npQjCUrb1E1Y6QTO/dz8b3rL0bM2uwAM30wJ9b0Vg5uuJPTn+THPwBPgSdwZumxw/2J2P25FgC6pDYcoAmKHRnHojU+v3ssYHi/HNAUhNfR6Qg=="
Feb 25 13:22:46 volumio go-librespot[24470]: time="2026-02-25T13:22:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:22:46 volumio go-librespot[24470]: time="2026-02-25T13:22:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.73:55994->104.199.65.9:4070: read: connection reset by peer"
Feb 25 13:22:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:22:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:22:48 volumio volumio[1007]: info: go-librespot daemon successfully initialized
Feb 25 13:22:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 25 13:22:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:49 volumio go-librespot[24479]: go-librespot daemon starting...
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=debug msg="app state loaded"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=info msg="zeroconf server listening on port 37673"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=debug msg="obtained new client token: AADHLu/RTtjWJnB5bwqO8PYT5Lc9c3kBg056bTELlHkDu3Q7a9ph3oHL/usc3kEdXRinRU+0ov3ehK//tkhB3XhmFKdrnZfAg7AJtuiDei/69d0kXSnLXilnS86keaoKS4FsD/iF+IZxn7LEhH+13OuE0NR9gvypd0gZFjb8QRXUVrDucS8BBG5mh3mAA+y/ugHo9p87Mq4cPigt5ml+kHAU7cFShy4hSodhHhMJsAvdLH9SSVTL6L6PGA=="
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:22:49 volumio go-librespot[24480]: time="2026-02-25T13:22:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 25 13:22:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:22:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:22:51 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:22:51 volumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:22:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 25 13:22:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:53 volumio go-librespot[24488]: go-librespot daemon starting...
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=debug msg="app state loaded"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=info msg="zeroconf server listening on port 45091"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=debug msg="obtained new client token: AAAvPeEkaWMwTVlVVdnr72jyQ2PYnw26FKFRazvhLiLNOhdMLpGqoSKaQKjG0XsuTW7WR6NLkPR4iBspcAQeyPOcw7XCK1uJGuEKRI0nM5X0Pp5EYn4ur5C5Z6BSTMCdZvjxi8d9XJsCoc4J3D2ULGwHwrM/tbeDx9o/q2m1EKAyPogcMY8pmKjhh63Xxnov04ATCaFAYE5ccavLMwvIPI7QWht61iSVl5CXkdX1A10cs2nU3UgyE+kWIA=="
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=debug msg="connected to ap-gew1.spotify.com:443"
Feb 25 13:22:53 volumio go-librespot[24489]: time="2026-02-25T13:22:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 25 13:22:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:22:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:22:54 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:22:54 volumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:22:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 25 13:22:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:22:56 volumio go-librespot[24511]: go-librespot daemon starting...
Feb 25 13:22:56 volumio go-librespot[24512]: time="2026-02-25T13:22:56Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:22:56 volumio go-librespot[24512]: time="2026-02-25T13:22:56Z" level=debug msg="app state loaded"
Feb 25 13:22:56 volumio go-librespot[24512]: time="2026-02-25T13:22:56Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:22:57 volumio go-librespot[24512]: time="2026-02-25T13:22:57Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:22:57 volumio go-librespot[24512]: time="2026-02-25T13:22:57Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:22:57 volumio go-librespot[24512]: time="2026-02-25T13:22:57Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:22:57 volumio go-librespot[24512]: time="2026-02-25T13:22:57Z" level=info msg="zeroconf server listening on port 43139"
Feb 25 13:22:57 volumio go-librespot[24512]: time="2026-02-25T13:22:57Z" level=debug msg="obtained new client token: AADrdTl/pWLCMfhCLJal2fzYq5vP+vtPaN4awAA90zN3reDVxDYDCmOVwR7HnTki919iPm/+x2opTqd5vwyzHifkoe+b+K8YPxcKH7Nxxosw9uILQcX6kDQDSmiOTbxZ0tvqwP7JZrdtOcHDxLMUGV6EHMlluFMnoSaVjf5sOhEOfKXSP4pVsZfjfnXAcHzfYQQCl1oYA0kF6ED4dRYeeffkricn50umvhmpfvpIiv3gQ+ojtoU/95AB7Q=="
Feb 25 13:22:57 volumio go-librespot[24512]: time="2026-02-25T13:22:57Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:22:57 volumio go-librespot[24512]: time="2026-02-25T13:22:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 25 13:22:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:22:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:22:57 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:22:57 volumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:23:00 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:23:00 volumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:23:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 25 13:23:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:00 volumio go-librespot[24522]: go-librespot daemon starting...
Feb 25 13:23:00 volumio go-librespot[24523]: time="2026-02-25T13:23:00Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:23:00 volumio go-librespot[24523]: time="2026-02-25T13:23:00Z" level=debug msg="app state loaded"
Feb 25 13:23:00 volumio go-librespot[24523]: time="2026-02-25T13:23:00Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:23:00 volumio go-librespot[24523]: time="2026-02-25T13:23:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:23:00 volumio go-librespot[24523]: time="2026-02-25T13:23:00Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:23:00 volumio go-librespot[24523]: time="2026-02-25T13:23:00Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:23:01 volumio go-librespot[24523]: time="2026-02-25T13:23:01Z" level=info msg="zeroconf server listening on port 38817"
Feb 25 13:23:01 volumio go-librespot[24523]: time="2026-02-25T13:23:01Z" level=debug msg="obtained new client token: AADuG1ariig8pkVKIKELyGAq6K0ti1GR8JuYzZ++44todcX+usY94A/yY0S3zR5rnmrJlDI2Bp88elHcJoTXivvay7vHPunU/J/qdlj42oMK0RfNFEAvwtz0W2DgWwENDjKAv1qH8Y2P91c3A7UNp5H8jI3Z9+nCz+9ZnN4kzGXTm6XChHsNhKK8Oeg4WXS6uZNI9m9B5PmTiwZkOvJuAE+X47/54PAefI/YTXJLnleqN6UVrKuH0fI="
Feb 25 13:23:01 volumio go-librespot[24523]: time="2026-02-25T13:23:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:23:01 volumio go-librespot[24523]: time="2026-02-25T13:23:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 25 13:23:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:23:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:23:03 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:23:03 volumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:23:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 25 13:23:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:04 volumio go-librespot[24531]: go-librespot daemon starting...
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=debug msg="app state loaded"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=info msg="zeroconf server listening on port 38099"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=debug msg="obtained new client token: AAC9sB+r2vhWXPFGVAHpBql6VFnLzlbH04bQTiqVzuHyDAOpNHZNjkUzBYHF+TCthIpzuhocb8yVAaNYTUHScGegC3GHUuwc4/rA/ME7Ik4T1r2soqgcFZE3XotDsZCbLyWZRHHVr95/fLZRYV0vlHZ/a+4z3YP+v20Zgi+DPT1jQWilv4SuGiHaTQsusNWgzjfQ2QcF2IGfbfoXfP5k5g1Wf+xYR5FCSqI2lyIuFQ8ymO/ph/12QjMtBw=="
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:23:04 volumio go-librespot[24532]: time="2026-02-25T13:23:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 25 13:23:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:23:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:23:06 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:23:06 volumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:23:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 25 13:23:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:08 volumio go-librespot[24553]: go-librespot daemon starting...
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=debug msg="app state loaded"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=info msg="zeroconf server listening on port 34973"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=debug msg="obtained new client token: AAA4Vupuu2g2MzAnabI+mGyoEm42xNZ2WO3YvWZT5BKV0e5Zh7MDoMMG8UPxDJjaje0n7vJZ/EGK6RZYfvPOmtF7Sq+LACmjIGK2/S0z4ETL6Wv6AZH+Bp6/GIXNkial+/eIYxXXL8uCgCNsBy7nS0iUkn718ge8iBLc+/TA+rUHbnlQYxQfX1VM9wMuHvdcyIZLTRj6hTeO+k0JM4whkQBJQ6JjTUeGUMRjhL0LitLvbHQZBbupZhloow=="
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:23:08 volumio go-librespot[24554]: time="2026-02-25T13:23:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 25 13:23:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:23:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:23:09 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:23:09 volumio volumio[1007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:23:09 volumio volumio[1007]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify
Feb 25 13:23:09 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 25 13:23:09 volumio volumio[1007]: Cannot find translation for source YouTube Music
Feb 25 13:23:09 volumio volumio[1007]: info: Disabling plugin spop
Feb 25 13:23:09 volumio volumio[1007]: info: Done.
Feb 25 13:23:09 volumio sudo[24562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service
Feb 25 13:23:09 volumio sudo[24562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 25 13:23:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:09 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:23:09 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:23:09 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:23:09 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:23:09 volumio sudo[24562]: pam_unix(sudo:session): session closed for user root
Feb 25 13:23:11 volumio volumio[1007]: info: Enabling plugin spop
Feb 25 13:23:11 volumio volumio[1007]: info: Loading plugin "spop"...
Feb 25 13:23:11 volumio volumio[1007]: info: PLUGIN START: spop
Feb 25 13:23:11 volumio volumio[1007]: info: Creating Spotify config file
Feb 25 13:23:11 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 25 13:23:11 volumio volumio[1007]: info: Done.
Feb 25 13:23:11 volumio volumio[1007]: info: Spotify config file written
Feb 25 13:23:11 volumio volumio[1007]: info: No need to fix Spotify hosts
Feb 25 13:23:11 volumio sudo[24566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 25 13:23:11 volumio sudo[24566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 25 13:23:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:23:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 25 13:23:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:11 volumio go-librespot[24568]: go-librespot daemon starting...
Feb 25 13:23:12 volumio sudo[24566]: pam_unix(sudo:session): session closed for user root
Feb 25 13:23:12 volumio volumio[1007]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 25 13:23:12 volumio volumio[1007]: SPOTIFY: BQAsa2kreWZGQRfzgglFEj04wriszvL8WWOgixCLn3YYnHtxFXvMh9BmnQH9AL1ov3dpksjMjgI5RTRsP60Xwj7zjSUSNmuTSyaSFbgBtoOwtDKtV1RLrQa05qqlg30k6NnJLcpMxyktk_DSGvcLZGKZr-PK6nDQNi4tEnNxeGuTyfofYEj4sJWjeI_OMR0DWVJI5Y1-l_Y1zon-8WmNfTNaqR-Wdhi1feAvcD4vS_5ZAiYj61xinPt1W11_fkZjov-4lRywLw_TK8bVcCa_i3gZ9pz2g-a3gKMe
Feb 25 13:23:12 volumio volumio[1007]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 25 13:23:12 volumio volumio[1007]: info: New Spotify access token = BQAsa2kreWZGQRfzgglFEj04wriszvL8WWOgixCLn3YYnHtxFXvMh9BmnQH9AL1ov3dpksjMjgI5RTRsP60Xwj7zjSUSNmuTSyaSFbgBtoOwtDKtV1RLrQa05qqlg30k6NnJLcpMxyktk_DSGvcLZGKZr-PK6nDQNi4tEnNxeGuTyfofYEj4sJWjeI_OMR0DWVJI5Y1-l_Y1zon-8WmNfTNaqR-Wdhi1feAvcD4vS_5ZAiYj61xinPt1W11_fkZjov-4lRywLw_TK8bVcCa_i3gZ9pz2g-a3gKMe
Feb 25 13:23:12 volumio volumio[1007]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=debug msg="app state loaded"
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:23:12 volumio volumio[1007]: SPOTIFY: User informations: {"country":"GB","display_name":"1123700120","email":"jason.duncalf@btinternet.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1123700120"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/1123700120","id":"1123700120","images":[],"product":"premium","type":"user","uri":"spotify:user:1123700120"}
Feb 25 13:23:12 volumio volumio[1007]: info: Spotify Successfully logged in
Feb 25 13:23:12 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 25 13:23:12 volumio volumio[1007]: info: [1772025792228] CoreMusicLibrary::Adding element Spotify
Feb 25 13:23:12 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 25 13:23:12 volumio volumio[1007]: Cannot find translation for source YouTube Music
Feb 25 13:23:12 volumio volumio[1007]: Cannot find translation for source Spotify
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=info msg="zeroconf server listening on port 33869"
Feb 25 13:23:12 volumio volumio[1007]: info: Initializing connection to go-librespot Websocket
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=debug msg="new websocket client"
Feb 25 13:23:12 volumio volumio[1007]: info: Connection to go-librespot Websocket established
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=debug msg="obtained new client token: AACvqwgsO8N8GnXqmxsp531UZ4LZalW00qVAfnUskAIygsqj++uYFR0vVIBep4PIlcGqyyr7dMyQRy+iT89vXFjdno2YP5IkCglPF0ttiyXr9kn3FdqSoZUcu+BTNiRndDAmWAMxnzMaHFi5IgVaeNbIQdAO4YkR6ej99K25FCubEEfVTXKsKw2VS3G0iZIY/t8ZsCZix00k5vK8rEbbmKT1W59OwKe+FC4h3qC/oI0UnAe/3O5UvTL70A=="
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:23:12 volumio go-librespot[24569]: time="2026-02-25T13:23:12Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 25 13:23:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 13:23:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 25 13:23:12 volumio volumio[1007]: info: Connection to go-librespot Websocket closed
Feb 25 13:23:15 volumio volumio[1007]: info: go-librespot daemon successfully initialized
Feb 25 13:23:15 volumio volumio[1007]: info: Getting Spotify volume
Feb 25 13:23:15 volumio volumio[1007]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 25 13:23:15 volumio volumio[1007]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 25 13:23:15 volumio volumio[1007]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 25 13:23:15 volumio volumio[1007]: errno: -111,
Feb 25 13:23:15 volumio volumio[1007]: code: 'ECONNREFUSED',
Feb 25 13:23:15 volumio volumio[1007]: syscall: 'connect',
Feb 25 13:23:15 volumio volumio[1007]: address: '127.0.0.1',
Feb 25 13:23:15 volumio volumio[1007]: port: 9879,
Feb 25 13:23:15 volumio volumio[1007]: response: undefined
Feb 25 13:23:15 volumio volumio[1007]: }
Feb 25 13:23:15 volumio volumio[1007]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 25 13:23:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 25 13:23:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 25 13:23:15 volumio go-librespot[24603]: go-librespot daemon starting...
Feb 25 13:23:15 volumio go-librespot[24604]: time="2026-02-25T13:23:15Z" level=info msg="running go-librespot 0.4.0"
Feb 25 13:23:15 volumio go-librespot[24604]: time="2026-02-25T13:23:15Z" level=debug msg="app state loaded"
Feb 25 13:23:15 volumio go-librespot[24604]: time="2026-02-25T13:23:15Z" level=info msg="api server listening on 127.0.0.1:9879"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=info msg="zeroconf server listening on port 36309"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="obtained new client token: AACnA//+GfzrdMBfLqpYk0jhwNzon+lYhDYpJPSQKNm0D++zfJt8EkWSNCzawBDq422Y+Km4HWJ9MZNeAbuaYotFtx5zbj7V8nNRetz9xDIZmlPrKG5LlHnZ4CPkIzRHOff2GMMv3Ox3u9df5nw5UOfqgFBDYfP6E2w90yHQwreN5FEcWj0el2IKlORLnBbqqRB64CGJE5l25PAPqyo22Fv8AFQ+iaRztgrsnRhAUB/uP5H6BUOLWrCI+Q=="
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="completed keyexchange"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="completed challenge"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=info msg="authenticated AP" username="11******20"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=info msg="authenticated Login5" username="11******20"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="initializing zeroconf session" username="11******20"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="dealer connection opened"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=trace msg="starting accesspoint recv loop"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=trace msg="starting dealer recv loop"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=trace msg="received accesspoint ping"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=debug msg="received connection id: ZjhmODJmYjEtNGQx...RkNGNTVFMDA4NQ=="
Feb 25 13:23:16 volumio go-librespot[24604]: time="2026-02-25T13:23:16Z" level=trace msg="received accesspoint pong ack"
Feb 25 13:23:17 volumio go-librespot[24604]: time="2026-02-25T13:23:17Z" level=debug msg="put connect state because NEW_DEVICE"
Feb 25 13:23:17 volumio go-librespot[24604]: time="2026-02-25T13:23:17Z" level=debug msg="update volume requested to 65535/65535"
Feb 25 13:23:17 volumio sudo[24614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 13:22'
Feb 25 13:23:17 volumio sudo[24614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 25 13:23:17 volumio go-librespot[24604]: time="2026-02-25T13:23:17Z" level=debug msg="put connect state because VOLUME_CHANGED"
Feb 25 13:23:17 volumio go-librespot[24604]: time="2026-02-25T13:23:17Z" level=trace msg="emitting websocket event: volume"
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="b5a4a000e056eaff366fbb6591bf2240b12246d0"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat Nov 8 06:10:52 UTC 2025"
VOLUMIO_VERSION="4.067"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="78c9815e90cf3bee23e5cdc5934a01e9"