Mar 24 15:34:00 katarynka go-librespot[12830]: time="2026-03-24T15:34:00+01:00" level=info msg="zeroconf server listening on port 45391" Mar 24 15:34:00 katarynka sudo[12840]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 15:34:00 katarynka sudo[12840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:00 katarynka sudo[12840]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:00 katarynka sudo[12838]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 15:34:00 katarynka volumio[12615]: info: MPD Permissions set Mar 24 15:34:00 katarynka sudo[12838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:00 katarynka volumio[12615]: info: MPD Permissions set Mar 24 15:34:00 katarynka volumio[12615]: info: VolumeController:: Volume=96 Mute =false Mar 24 15:34:00 katarynka volumio[12615]: info: CoreStateMachine::pushState Mar 24 15:34:00 katarynka sudo[12838]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:00 katarynka volumio[12615]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::volumioPushState Mar 24 15:34:00 katarynka volumio[12615]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 15:34:00 katarynka volumio[12615]: info: Discovery: Found device katarynka Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:00 katarynka volumio[12615]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:00 katarynka volumio-remote-updater[622]: [2026-03-24 15:34:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774362838 101 Mar 24 15:34:00 katarynka volumio[12735]: Starting albumart workers Mar 24 15:34:00 katarynka volumio[12736]: Starting albumart workers Mar 24 15:34:00 katarynka volumio[12615]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 24 15:34:00 katarynka volumio[12615]: info: Volumio called home Mar 24 15:34:00 katarynka volumio[12615]: info: Spotify config file written Mar 24 15:34:00 katarynka volumio[12615]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 15:34:00 katarynka volumio[12615]: info: Discovery: Found device katarynka Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:00 katarynka volumio[12615]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:00 katarynka volumio[12615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 24 15:34:00 katarynka sudo[12845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 15:34:00 katarynka sudo[12845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:00 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 15:34:01 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 15:34:01 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:01 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:01 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:01 katarynka go-librespot[12854]: go-librespot daemon starting... Mar 24 15:34:01 katarynka sudo[12845]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:01 katarynka volumio[12615]: info: No need to fix Spotify hosts Mar 24 15:34:01 katarynka go-librespot[12858]: time="2026-03-24T15:34:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:01 katarynka go-librespot[12858]: time="2026-03-24T15:34:01+01:00" level=debug msg="app state loaded" Mar 24 15:34:01 katarynka go-librespot[12858]: time="2026-03-24T15:34:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:01 katarynka go-librespot[12858]: time="2026-03-24T15:34:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:01 katarynka go-librespot[12858]: time="2026-03-24T15:34:01+01: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]" Mar 24 15:34:01 katarynka go-librespot[12858]: time="2026-03-24T15:34:01+01: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]" Mar 24 15:34:01 katarynka go-librespot[12858]: time="2026-03-24T15:34:01+01:00" level=info msg="zeroconf server listening on port 43231" Mar 24 15:34:02 katarynka go-librespot[12858]: time="2026-03-24T15:34:02+01:00" level=debug msg="obtained new client token: AAACSVc6bOseBrlRnRUvaEXFUTbUsw6JxsFRyd7oDS4TrcPW6Ckibau9TeCo5vt3osm9S7crWK/axhJTUtAas1c1Ke0H4PSGw6/KBAvHdsT1vFDIW59mLWCjbvk0kwhzRlg4hCfwdQq6S1eeKfNsXn4koqxyFski88V7dAlSmNNVoiMl842BkrQSxMfVkcmiBw3WTk84shqCVjir6bHpczVfbCRJ+pz5Do/n1ON8d/NdWzRs6J+38ZQQ" Mar 24 15:34:02 katarynka go-librespot[12858]: time="2026-03-24T15:34:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:02 katarynka volumio[12615]: info: Starting Shairport Sync Mar 24 15:34:02 katarynka go-librespot[12858]: time="2026-03-24T15:34:02+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:02 katarynka go-librespot[12858]: time="2026-03-24T15:34:02+01:00" level=debug msg="completed challenge" Mar 24 15:34:02 katarynka volumio[12615]: info: Starting Shairport Sync Mar 24 15:34:02 katarynka volumio[12615]: info: Starting Shairport Sync Mar 24 15:34:02 katarynka go-librespot[12858]: time="2026-03-24T15:34:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:02 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:02 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:02 katarynka sudo[12867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:34:02 katarynka sudo[12867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:02 katarynka sudo[12874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:34:02 katarynka sudo[12874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:02 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 15:34:02 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 15:34:02 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:02 katarynka systemd[1]: shairport-sync.service: Consumed 2.455s CPU time. Mar 24 15:34:02 katarynka sudo[12877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:34:02 katarynka sudo[12877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:02 katarynka sudo[12879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 15:34:02 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:02 katarynka sudo[12879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:02 katarynka sudo[12867]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:02 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 15:34:02 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 15:34:02 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:02 katarynka sudo[12879]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:03 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:03 katarynka sudo[12874]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:03 katarynka sudo[12877]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:03 katarynka volumio[12615]: info: Shairport-Sync Started Mar 24 15:34:03 katarynka volumio[12615]: Error adding Membership: Error: addMembership EINVAL Mar 24 15:34:03 katarynka volumio[12615]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 15:34:03 katarynka volumio[12615]: info: Shairport-Sync Started Mar 24 15:34:03 katarynka volumio[12615]: info: Upmpdcli Daemon Started Mar 24 15:34:03 katarynka volumio[12615]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:03 katarynka volumio[12615]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:03 katarynka volumio[12615]: info: Shairport-Sync Started Mar 24 15:34:05 katarynka volumio[12615]: info: go-librespot daemon successfully initialized Mar 24 15:34:05 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 15:34:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:05 katarynka go-librespot[12926]: go-librespot daemon starting... Mar 24 15:34:05 katarynka systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 24 15:34:05 katarynka go-librespot[12927]: time="2026-03-24T15:34:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:05 katarynka go-librespot[12927]: time="2026-03-24T15:34:05+01:00" level=debug msg="app state loaded" Mar 24 15:34:05 katarynka go-librespot[12927]: time="2026-03-24T15:34:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:05 katarynka mpd[12811]: 2026-03-24T15:34:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 15:34:05 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 15:34:05 katarynka sudo[12772]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:05 katarynka sudo[12782]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:06 katarynka volumio[12615]: info: Completed starting Core Plugins Mar 24 15:34:06 katarynka volumio[12615]: info: ------------------------------------------- Mar 24 15:34:06 katarynka volumio[12615]: info: ----- MyVolumio plugins startup ---- Mar 24 15:34:06 katarynka volumio[12615]: info: ------------------------------------------- Mar 24 15:34:06 katarynka volumio[12615]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=info msg="zeroconf server listening on port 43823" Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=debug msg="obtained new client token: AAAJWFYsX/T0FdCUoh2x74Vy1SwCUv1DfK+3wrS1HUGEuusE2PpkobjrPGHfBzad4cuknanKhAC0YH6yDi9pCWAXB8e8kW6pU8vu4Hzoqe83y/n6f3YFIuFx1OG617PaN7d3aZ3jRstdg2tzy4qd0D7SBwOTy2vZ31RjdnWqmzzVOJm/5mOXRst63/YiBQfNZ/Zanlya6ena0z8yBee5wivK/PHSVXfzxDpzgL7RrgQjBhQjzvAWG4Wf" Mar 24 15:34:06 katarynka volumio[12615]: error: MPD error: The expression evaluated to a falsy value: Mar 24 15:34:06 katarynka volumio[12615]: assert.ok(self.idling) Mar 24 15:34:06 katarynka volumio[12615]: error: The expression evaluated to a falsy value: Mar 24 15:34:06 katarynka volumio[12615]: assert.ok(self.idling) Mar 24 15:34:06 katarynka volumio[12615]: error: updateQueue error: null Mar 24 15:34:06 katarynka volumio[12615]: info: MPD running with PID12811 Mar 24 15:34:06 katarynka volumio[12615]: ,establishing connection Mar 24 15:34:06 katarynka volumio[12615]: error: updateQueue error: null Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=debug msg="completed challenge" Mar 24 15:34:06 katarynka go-librespot[12927]: time="2026-03-24T15:34:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:07 katarynka systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 24 15:34:07 katarynka systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 24 15:34:07 katarynka systemd[1]: setdatetime-helper.service: Consumed 1.890s CPU time. Mar 24 15:34:08 katarynka volumio[12615]: info: Initializing connection to go-librespot Websocket Mar 24 15:34:08 katarynka volumio[12615]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:34:09 katarynka sudo[12982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 15:34:09 katarynka sudo[12982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:09 katarynka sudo[12984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 15:34:09 katarynka sudo[12984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:09 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 15:34:09 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 15:34:09 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 15:34:09 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 15:34:09 katarynka sudo[12982]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:09 katarynka mpd_monitor.sh[12987]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 15:34:09 katarynka sudo[12984]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:09 katarynka volumio[12615]: info: Successfully started MPD Monitor Mar 24 15:34:09 katarynka volumio[12615]: info: Successfully started MPD Monitor Mar 24 15:34:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 15:34:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:09 katarynka go-librespot[12991]: go-librespot daemon starting... Mar 24 15:34:09 katarynka go-librespot[12992]: time="2026-03-24T15:34:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:09 katarynka go-librespot[12992]: time="2026-03-24T15:34:09+01:00" level=debug msg="app state loaded" Mar 24 15:34:09 katarynka go-librespot[12992]: time="2026-03-24T15:34:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01: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]" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01: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]" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01:00" level=info msg="zeroconf server listening on port 46623" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01:00" level=debug msg="obtained new client token: AAAVcviyQ1ss1LlGR0flDfnQEscZbc2gImGs0iPtchkkPD6wv9hidfws2SFYUfF99A8Y6B4zP1r1b8l/dbGpwLYHSlURXT9Bhgi9dIQcmLFZqFmH/JwVg/UOvxV3VxSafKWl+x/Qnta0pIk4gp0JL6u+cz8CCFal6RQ2Ta1vjV/EYhHaC5jsT1H0wGt6e5kIx9JiAB+jhwCnjLyd3FEnVPI+pnQm6R1yIVgG8n29tYRHycTQc6I2EI8QkEE=" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01:00" level=debug msg="completed challenge" Mar 24 15:34:10 katarynka go-librespot[12992]: time="2026-03-24T15:34:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:11 katarynka volumio[12615]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 15:34:11 katarynka volumio[12615]: info: Initializing connection to go-librespot Websocket Mar 24 15:34:11 katarynka volumio[12615]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:34:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 24 15:34:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:13 katarynka go-librespot[12999]: go-librespot daemon starting... Mar 24 15:34:13 katarynka go-librespot[13000]: time="2026-03-24T15:34:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:13 katarynka go-librespot[13000]: time="2026-03-24T15:34:13+01:00" level=debug msg="app state loaded" Mar 24 15:34:13 katarynka go-librespot[13000]: time="2026-03-24T15:34:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 15:34:14 katarynka volumio[12615]: info: Initializing connection to go-librespot Websocket Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="new websocket client" Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=info msg="zeroconf server listening on port 37679" Mar 24 15:34:14 katarynka volumio[12615]: info: Connection to go-librespot Websocket established Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 15:34:14 katarynka volumio[12615]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 15:34:14 katarynka volumio[12615]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="obtained new client token: AACItzPH+CrHcWV9tVfHhoIhT+G1lpXtJNCE8ISe6uCTmcpcen/edTZupGW26N01LTGMGRwBTlNrWP+j6VBvhVRB/H1SO7ktS0/mTtQYOSPEaDStzLkB7Ym9llupuDhmaqE/bBCAUNPpLdHYku9FdcBqqLNxiSZ9dx3uEiImMhX7aNzcyo//3bLZKg/6UoAzMb6r0k5P8iNxKuMl+ASSfmcjRt2IHte2uP1tzg0DCg56Uv8ubwKRUlVOwWQ=" Mar 24 15:34:14 katarynka volumio[12615]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 15:34:14 katarynka volumio[12615]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 15:34:14 katarynka volumio[12615]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 15:34:14 katarynka volumio[12615]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 15:34:14 katarynka volumio[12615]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 15:34:14 katarynka volumio[12615]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=debug msg="completed challenge" Mar 24 15:34:14 katarynka go-librespot[13000]: time="2026-03-24T15:34:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:16 katarynka volumio[12615]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 15:34:16 katarynka volumio[12615]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 15:34:16 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:16 katarynka volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:16 katarynka volumio[12615]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 15:34:16 katarynka volumio[12615]: info: MyVolumio login type: Token Mar 24 15:34:16 katarynka volumio[12615]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 15:34:16 katarynka volumio[12615]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 15:34:17 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 24 15:34:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:17 katarynka go-librespot[13007]: go-librespot daemon starting... Mar 24 15:34:17 katarynka go-librespot[13008]: time="2026-03-24T15:34:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:17 katarynka go-librespot[13008]: time="2026-03-24T15:34:17+01:00" level=debug msg="app state loaded" Mar 24 15:34:17 katarynka go-librespot[13008]: time="2026-03-24T15:34:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:18 katarynka go-librespot[13008]: time="2026-03-24T15:34:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:18 katarynka go-librespot[13008]: time="2026-03-24T15:34:18+01: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]" Mar 24 15:34:18 katarynka go-librespot[13008]: time="2026-03-24T15:34:18+01: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]" Mar 24 15:34:18 katarynka go-librespot[13008]: time="2026-03-24T15:34:18+01:00" level=info msg="zeroconf server listening on port 35511" Mar 24 15:34:18 katarynka volumio[12615]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 15:34:18 katarynka volumio[12615]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 15:34:18 katarynka volumio[12615]: info: Streaming services startup Mar 24 15:34:18 katarynka volumio[12615]: info: Starting Streaming Daemon Mar 24 15:34:18 katarynka go-librespot[13008]: time="2026-03-24T15:34:18+01:00" level=debug msg="obtained new client token: AABPVoe3+G0/NQAZ3gQ3D+8H9Bs4PCvPUXGY1vhYnGprpyrBNV6KhDNndqPor+b3ypDhbrvZ7l7FPUkQqT5QKS+8CC13sAjl6jNwaWEt3kSNcWDPp7nf7ia9+Ie1cZ/TtPVIIP/QFcLEAZmRIKkjS4aKfO+cZRT3fAgJ1hjf0xC307cEKJRsarCV7i5dby1Jd9kcUAt6MObygXm8YXKArV6mjUUfQpBwO+BoVTJsQDEL7Rmf4iRP5k223xE=" Mar 24 15:34:18 katarynka sudo[13017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 15:34:18 katarynka sudo[13017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:18 katarynka volumio[12615]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 15:34:18 katarynka sudo[13017]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:18 katarynka volumio[12615]: info: Getting Spotify volume Mar 24 15:34:18 katarynka volumio[12615]: info: Connection to go-librespot Websocket closed Mar 24 15:34:18 katarynka volumio[12615]: error: Cannot start Volumio Streaming Daemon Mar 24 15:34:18 katarynka volumio[12615]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 15:34:18 katarynka volumio[12615]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 15:34:18 katarynka go-librespot[13008]: time="2026-03-24T15:34:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:18 katarynka volumio[12615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 24 15:34:19 katarynka go-librespot[13008]: time="2026-03-24T15:34:19+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:19 katarynka go-librespot[13008]: time="2026-03-24T15:34:19+01:00" level=debug msg="completed challenge" Mar 24 15:34:19 katarynka volumio[12615]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:19 katarynka volumio[12615]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:19 katarynka volumio[12615]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 24 15:34:19 katarynka volumio[12615]: SPOTIFY: SPOTIFY VOLUME undefined Mar 24 15:34:19 katarynka volumio[12615]: SPOTIFY: VOLUMIO VOLUME 96 Mar 24 15:34:19 katarynka volumio[12615]: info: Aligning Spotify Volume to Volumio Volume Mar 24 15:34:19 katarynka volumio[12615]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:19 katarynka volumio[12615]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:19 katarynka volumio[12615]: info: Setting Spotify Volume from Volumio: 96 Mar 24 15:34:19 katarynka go-librespot[13008]: time="2026-03-24T15:34:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:19 katarynka volumio[12615]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 15:34:19 katarynka volumio[12615]: Error: socket hang up Mar 24 15:34:19 katarynka volumio[12615]: at connResetException (node:internal/errors:720:14) Mar 24 15:34:19 katarynka volumio[12615]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 24 15:34:19 katarynka volumio[12615]: at Socket.emit (node:events:526:35) Mar 24 15:34:19 katarynka volumio[12615]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 24 15:34:19 katarynka volumio[12615]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 24 15:34:19 katarynka volumio[12615]: code: 'ECONNRESET', Mar 24 15:34:19 katarynka volumio[12615]: response: undefined Mar 24 15:34:19 katarynka volumio[12615]: } Mar 24 15:34:19 katarynka volumio[12615]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 15:34:20 katarynka sudo[13051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 15:33' Mar 24 15:34:20 katarynka sudo[13051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:21 katarynka sudo[13051]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:21 katarynka volumio-remote-updater[622]: [2026-03-24 15:34:21] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 15:34:21 katarynka volumio-remote-updater[622]: [2026-03-24 15:34:21] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 15:34:21 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:21 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 15:34:21 katarynka systemd[1]: volumio.service: Consumed 49.642s CPU time. Mar 24 15:34:21 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 15:34:21 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 15:34:21 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 25040. Mar 24 15:34:21 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 15:34:21 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 15:34:21 katarynka systemd[1]: volumio.service: Consumed 49.642s CPU time. Mar 24 15:34:21 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 15:34:21 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 15:34:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 24 15:34:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:22 katarynka go-librespot[13087]: go-librespot daemon starting... Mar 24 15:34:22 katarynka go-librespot[13088]: time="2026-03-24T15:34:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:22 katarynka go-librespot[13088]: time="2026-03-24T15:34:22+01:00" level=debug msg="app state loaded" Mar 24 15:34:22 katarynka go-librespot[13088]: time="2026-03-24T15:34:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:22 katarynka go-librespot[13088]: time="2026-03-24T15:34:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:22 katarynka go-librespot[13088]: time="2026-03-24T15:34:22+01: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]" Mar 24 15:34:22 katarynka go-librespot[13088]: time="2026-03-24T15:34:22+01: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]" Mar 24 15:34:22 katarynka go-librespot[13088]: time="2026-03-24T15:34:22+01:00" level=info msg="zeroconf server listening on port 41733" Mar 24 15:34:23 katarynka go-librespot[13088]: time="2026-03-24T15:34:23+01:00" level=debug msg="obtained new client token: AADaatlnJ0M995TSLqsgcaaSVPyY+W+d0bbLS7vMp75l/BbfM72AHzfeUShYVXSDh9l3G3/9jbk7Ot366qShNkmVRteLqcylPsS4gX9tqmHerXSnQ7u7I3beRHOyPp/3WwPa/sdU/HNU+NY6SKG02f1NzLM2tO4oVpYhIB/Hb0iuV1OLlX68XMUXXDixM3csnEJ58Frvpq4OQ8IlXjWAS280KlgeHLQb/sLbGdYjsJLpjmz6GrsfxBQc" Mar 24 15:34:23 katarynka go-librespot[13088]: time="2026-03-24T15:34:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:23 katarynka go-librespot[13088]: time="2026-03-24T15:34:23+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:23 katarynka go-librespot[13088]: time="2026-03-24T15:34:23+01:00" level=debug msg="completed challenge" Mar 24 15:34:23 katarynka go-librespot[13088]: time="2026-03-24T15:34:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:25 katarynka volumio[13072]: info: ------------------------------------------- Mar 24 15:34:25 katarynka volumio[13072]: info: ----- Volumio3 ---- Mar 24 15:34:25 katarynka volumio[13072]: info: ------------------------------------------- Mar 24 15:34:25 katarynka volumio[13072]: info: ----- System startup ---- Mar 24 15:34:25 katarynka volumio[13072]: info: ------------------------------------------- Mar 24 15:34:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 24 15:34:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:26 katarynka go-librespot[13102]: go-librespot daemon starting... Mar 24 15:34:26 katarynka go-librespot[13103]: time="2026-03-24T15:34:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:26 katarynka go-librespot[13103]: time="2026-03-24T15:34:26+01:00" level=debug msg="app state loaded" Mar 24 15:34:26 katarynka go-librespot[13103]: time="2026-03-24T15:34:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:26 katarynka volumio-remote-updater[622]: [2026-03-24 15:34:26] [connect] Successful connection Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01: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]" Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01: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]" Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01:00" level=info msg="zeroconf server listening on port 33859" Mar 24 15:34:27 katarynka volumio[13072]: info: MYVOLUMIO Environment detected Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01:00" level=debug msg="obtained new client token: AACtmEvnjNoRw7SH7t9AkcEncFhimcWJDapikMI3k+7ig7Tw17zTcVf+afWsd0C2CdusYsrz4tgBIGKAZhnc2yy9XLYUlmJBFimZS+U6b6QiJOZ8yugXXEyu1qJ8xRQI+tK2z6hlZi89oKofZ1YjReY4QdanNC5QQk2LqcJkSPT/qqCBIJtjiSt7H5HJPmVpvcj6Tn0DurWKb+OufiYGqsbmpe05MyOyh+NpQMDyLVrWH1Q65o3LYZXw" Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:27 katarynka volumio[13072]: info: Plugin folders cleanup Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning into folder /volumio/app/plugins/ Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning category audio_interface Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning category miscellanea Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning category music_service Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning category plugins.json Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning category system_controller Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning category user_interface Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning into folder /data/plugins/ Mar 24 15:34:27 katarynka volumio[13072]: info: Scanning category music_service Mar 24 15:34:27 katarynka volumio[13072]: info: Plugin folders cleanup completed Mar 24 15:34:27 katarynka volumio[13072]: info: ------------------------------------------- Mar 24 15:34:27 katarynka volumio[13072]: info: ----- Core plugins startup ---- Mar 24 15:34:27 katarynka volumio[13072]: info: ------------------------------------------- Mar 24 15:34:27 katarynka volumio[13072]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 15:34:27 katarynka volumio[13072]: info: Adding plugin upnp to MyMusic Plugins Mar 24 15:34:27 katarynka volumio[13072]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:27 katarynka volumio[13072]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01:00" level=debug msg="completed challenge" Mar 24 15:34:27 katarynka volumio[13072]: info: Loading plugins from folder /data/plugins/ Mar 24 15:34:27 katarynka volumio[13072]: info: Loading plugin "system"... Mar 24 15:34:27 katarynka go-librespot[13103]: time="2026-03-24T15:34:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:27 katarynka volumio[13072]: info: Loading plugin "appearance"... Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "network"... Mar 24 15:34:29 katarynka volumio[13072]: info: Refreshing Cached IP Addresses Mar 24 15:34:29 katarynka sudo[13121]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 15:34:29 katarynka sudo[13121]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:29 katarynka sudo[13121]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:29 katarynka sudo[13123]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 15:34:29 katarynka sudo[13123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "services"... Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "alsa_controller"... Mar 24 15:34:29 katarynka sudo[13123]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:29 katarynka sudo[13131]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 15:34:29 katarynka sudo[13131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:29 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "wizard"... Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "networkfs"... Mar 24 15:34:29 katarynka volumio[13072]: info: Starting Udev Watcher for removable devices Mar 24 15:34:29 katarynka volumio[13072]: info: Ignoring mount for partition: boot Mar 24 15:34:29 katarynka volumio[13072]: info: Ignoring mount for partition: volumio Mar 24 15:34:29 katarynka volumio[13072]: info: Ignoring mount for partition: volumio_data Mar 24 15:34:29 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "volumio_command_line_client"... Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "upnp"... Mar 24 15:34:29 katarynka volumio[13072]: info: [1774362869894] Starting Upmpd Daemon Mar 24 15:34:29 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "my_music"... Mar 24 15:34:29 katarynka volumio[13072]: info: Loading plugin "mpd"... Mar 24 15:34:30 katarynka sudo[13131]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:30 katarynka volumio[13072]: info: Loading plugin "upnp_browser"... Mar 24 15:34:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 24 15:34:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:30 katarynka go-librespot[13154]: go-librespot daemon starting... Mar 24 15:34:30 katarynka go-librespot[13155]: time="2026-03-24T15:34:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:30 katarynka go-librespot[13155]: time="2026-03-24T15:34:30+01:00" level=debug msg="app state loaded" Mar 24 15:34:30 katarynka go-librespot[13155]: time="2026-03-24T15:34:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:31 katarynka go-librespot[13155]: time="2026-03-24T15:34:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:34:31 katarynka go-librespot[13155]: time="2026-03-24T15:34:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:34:31 katarynka go-librespot[13155]: time="2026-03-24T15:34:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:34:31 katarynka go-librespot[13155]: time="2026-03-24T15:34:31+01:00" level=info msg="zeroconf server listening on port 37501" Mar 24 15:34:31 katarynka go-librespot[13155]: time="2026-03-24T15:34:31+01:00" level=debug msg="obtained new client token: AAC6C4l0BlMgMzlOkQu1ezv0my1FcmN/oJmxci9HEqGVahGjTIJfsCRCmkaqI+ZbIGucXKnx6H28tFyaU2TAWFlg8+6jJqw8hFseAc1GoZ2SRSQU4Duzn0Plc8CGbBUaShkZM3NPsDcf/J9zvsSteeE4QjStwXnxcB1f6XUoCHcwc7HX88u0zCummSfDIeoCv879GikdBKyBiE+7Z+Jrv3F+oQqJdpdPxmsFdbleuezzFYlAbg1a+ok2hNw=" Mar 24 15:34:31 katarynka go-librespot[13155]: time="2026-03-24T15:34:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:32 katarynka go-librespot[13155]: time="2026-03-24T15:34:32+01:00" 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" Mar 24 15:34:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:33 katarynka volumio[13072]: info: Starting UPNP Browser Mar 24 15:34:33 katarynka volumio[13072]: info: Loading plugin "alarm-clock"... Mar 24 15:34:33 katarynka volumio[13072]: info: Loading plugin "airplay_emulation"... Mar 24 15:34:34 katarynka volumio[13072]: info: Starting Shairport Sync Mar 24 15:34:34 katarynka volumio[13072]: info: Loading plugin "last_100"... Mar 24 15:34:34 katarynka volumio[13072]: info: Loading plugin "webradio"... Mar 24 15:34:34 katarynka volumio[13072]: info: Loading plugin "i2s_dacs"... Mar 24 15:34:34 katarynka volumio[13072]: info: Loading plugin "volumiodiscovery"... Mar 24 15:34:34 katarynka volumio[13072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 15:34:34 katarynka volumio[13072]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:34:34 katarynka volumio[13072]: *** WARNING *** For more information see Mar 24 15:34:34 katarynka volumio[13072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 15:34:34 katarynka volumio[13072]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:34:34 katarynka volumio[13072]: *** WARNING *** For more information see Mar 24 15:34:34 katarynka node[13072]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 15:34:34 katarynka node[13072]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:34:34 katarynka node[13072]: *** WARNING *** For more information see Mar 24 15:34:34 katarynka volumio[13072]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 15:34:34 katarynka node[13072]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 15:34:34 katarynka node[13072]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:34:34 katarynka node[13072]: *** WARNING *** For more information see Mar 24 15:34:34 katarynka volumio[13072]: info: Discovery: Started advertising with name: katarynka Mar 24 15:34:34 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 15:34:34 katarynka volumio[13072]: info: Loading plugin "spop"... Mar 24 15:34:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 24 15:34:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:35 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:35 katarynka go-librespot[13165]: go-librespot daemon starting... Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=debug msg="app state loaded" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=info msg="zeroconf server listening on port 45851" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=debug msg="obtained new client token: AADDKh4Hv5G+kSLweUCUWjyUtMG8iO7c2P1EHGJkXHO9TdOQz9p76QLs3hZJZXbgzifTZbPDHXxi9ttAXAk5mWib5TpVKV24vf6u5PztWk55zub+k2xIikxe61lMA7mOjP069Fmb9e51sGpcaAhxUocsKybx93cdDa+dacHxOexZVm+X/6FC7Dl6n89nBK+dmacjlE6tKV9Q2cHfR0lhxvY3ee7gvvO8qiVyb2hTbyMmTyeb34RkI2DDwao=" Mar 24 15:34:35 katarynka go-librespot[13166]: time="2026-03-24T15:34:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:36 katarynka go-librespot[13166]: time="2026-03-24T15:34:36+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:36 katarynka go-librespot[13166]: time="2026-03-24T15:34:36+01:00" level=debug msg="completed challenge" Mar 24 15:34:36 katarynka go-librespot[13166]: time="2026-03-24T15:34:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:36 katarynka volumio[13072]: info: Loading plugin "outputs"... Mar 24 15:34:36 katarynka volumio[13072]: info: Loading plugin "albumart"... Mar 24 15:34:36 katarynka volumio[13072]: info: Plugin example_plugin is not enabled Mar 24 15:34:36 katarynka volumio[13072]: info: Loading plugin "inputs"... Mar 24 15:34:36 katarynka volumio[13072]: info: Loading plugin "updater_comm"... Mar 24 15:34:36 katarynka volumio[13072]: info: Plugin mpdemulation is not enabled Mar 24 15:34:36 katarynka volumio[13072]: info: Loading plugin "rest_api"... Mar 24 15:34:36 katarynka volumio[13072]: info: Loading plugin "websocket"... Mar 24 15:34:36 katarynka volumio[13072]: info: Starting Socket.io Server version 1.7.4 Mar 24 15:34:36 katarynka volumio[13072]: info: Loading i18n strings for locale pl Mar 24 15:34:36 katarynka volumio[13072]: Updating browse sources language Mar 24 15:34:36 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::initPlayerControls Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: Express server listening on port 3000 Mar 24 15:34:37 katarynka volumio[13072]: [Metrics] WebUI: 12s 539.64ms Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::resetVolumioState Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::getcurrentVolume Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 15:34:37 katarynka volumio[13072]: info: Cannot read play queue from file Mar 24 15:34:37 katarynka volumio[13072]: info: Volumio Network Manager: Network status updated: 2 Mar 24 15:34:37 katarynka volumio[13174]: Forking 3 albumart workers Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::setRepeat null single undefined Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::pushState Mar 24 15:34:37 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::volumioPushState Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::setRandom null Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::pushState Mar 24 15:34:37 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::volumioPushState Mar 24 15:34:37 katarynka volumio[13072]: info: Setting Device type: Raspberry PI Mar 24 15:34:37 katarynka volumio[13072]: info: Completed loading Core Plugins Mar 24 15:34:37 katarynka volumio[13072]: info: Preparing to generate the ALSA configuration file Mar 24 15:34:37 katarynka volumio[13072]: info: VolumeController:: Volume=96 Mute =false Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::pushState Mar 24 15:34:37 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::volumioPushState Mar 24 15:34:37 katarynka volumio[13072]: info: CoreStateMachine::updateTrackBlock Mar 24 15:34:37 katarynka volumio[13072]: info: CorePlayQueue::getTrackBlock Mar 24 15:34:37 katarynka volumio[13072]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 15:34:38 katarynka volumio[13072]: info: Asound.conf file unchanged, so no further update is needed Mar 24 15:34:38 katarynka volumio[13072]: info: Output device has changed, restarting MPD Mar 24 15:34:38 katarynka volumio[13072]: info: Output device has changed, restarting Shairport Sync Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:38 katarynka sudo[13228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 15:34:38 katarynka sudo[13228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:38 katarynka sudo[13230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 15:34:38 katarynka sudo[13230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:38 katarynka volumio[13072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 15:34:38 katarynka volumio[13072]: info: ___________ START PLUGINS ___________ Mar 24 15:34:38 katarynka sudo[13228]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:38 katarynka volumio[13072]: info: ControllerMpd::onStart: Initializing MPD Mar 24 15:34:38 katarynka volumio[13072]: info: Creating MPD Configuration file Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 15:34:38 katarynka volumio[13072]: info: [1774362878282] CoreMusicLibrary::Adding element Serwery Mediów Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:34:38 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 15:34:38 katarynka volumio[13072]: info: UPNP Browser: Client initialized successfully Mar 24 15:34:38 katarynka sudo[13238]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 15:34:38 katarynka sudo[13238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:38 katarynka sudo[13238]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:38 katarynka sudo[13240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 15:34:38 katarynka sudo[13240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:38 katarynka volumio[13072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:38 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 15:34:38 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 15:34:38 katarynka systemd[1]: mpd.service: Consumed 7.742s CPU time. Mar 24 15:34:38 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 15:34:38 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 15:34:38 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 15:34:38 katarynka volumio[13072]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 15:34:38 katarynka volumio[13072]: info: [1774362878567] CoreMusicLibrary::Adding element Last_100 Mar 24 15:34:38 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 15:34:38 katarynka volumio[13072]: info: [1774362878595] CoreMusicLibrary::Adding element Webradio Mar 24 15:34:38 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 15:34:38 katarynka volumio[13072]: info: Initializing BBC Radios Mar 24 15:34:38 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 15:34:38 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 15:34:38 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 15:34:38 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 15:34:38 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 15:34:38 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 15:34:38 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:38 katarynka volumio[13072]: info: Creating Spotify config file Mar 24 15:34:38 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 24 15:34:39 katarynka volumio-remote-updater[622]: [2026-03-24 15:34:39] [connect] Successful connection Mar 24 15:34:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:39 katarynka sudo[13259]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 15:34:39 katarynka sudo[13259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 15:34:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:39 katarynka go-librespot[13268]: go-librespot daemon starting... Mar 24 15:34:39 katarynka sudo[13259]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:39 katarynka go-librespot[13270]: time="2026-03-24T15:34:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:40 katarynka go-librespot[13270]: time="2026-03-24T15:34:40+01:00" level=info msg="zeroconf server listening on port 37117" Mar 24 15:34:40 katarynka volumio[13072]: info: Volumio Calling Home Mar 24 15:34:41 katarynka volumio[13072]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 15:34:41 katarynka sudo[13296]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 15:34:41 katarynka volumio[13072]: info: Discovery: Found device katarynka Mar 24 15:34:41 katarynka volumio[13072]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:41 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:41 katarynka sudo[13296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:41 katarynka sudo[13296]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:41 katarynka volumio[13072]: info: MPD Permissions set Mar 24 15:34:41 katarynka volumio[13072]: info: MPD Permissions set Mar 24 15:34:41 katarynka volumio[13072]: info: VolumeController:: Volume=96 Mute =false Mar 24 15:34:41 katarynka sudo[13298]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 15:34:41 katarynka sudo[13298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:41 katarynka volumio[13072]: info: CoreStateMachine::pushState Mar 24 15:34:41 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:41 katarynka sudo[13298]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:41 katarynka volumio[13072]: info: CoreCommandRouter::volumioPushState Mar 24 15:34:41 katarynka volumio[13072]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 15:34:41 katarynka volumio[13072]: info: Discovery: Found device katarynka Mar 24 15:34:41 katarynka volumio[13072]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:41 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:41 katarynka volumio-remote-updater[622]: [2026-03-24 15:34:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774362879 101 Mar 24 15:34:41 katarynka volumio[13072]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 24 15:34:41 katarynka volumio[13194]: Starting albumart workers Mar 24 15:34:41 katarynka volumio[13072]: info: Volumio called home Mar 24 15:34:41 katarynka volumio[13072]: info: Spotify config file written Mar 24 15:34:41 katarynka sudo[13302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 15:34:41 katarynka sudo[13302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:41 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 15:34:41 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 15:34:41 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:41 katarynka volumio[13195]: Starting albumart workers Mar 24 15:34:41 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:41 katarynka go-librespot[13304]: go-librespot daemon starting... Mar 24 15:34:41 katarynka sudo[13302]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:42 katarynka volumio[13072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=debug msg="app state loaded" Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13193]: Starting albumart workers Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:34:42 katarynka volumio[13072]: info: No need to fix Spotify hosts Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=info msg="zeroconf server listening on port 42899" Mar 24 15:34:42 katarynka volumio[13072]: info: Starting Shairport Sync Mar 24 15:34:42 katarynka volumio[13072]: info: Starting Shairport Sync Mar 24 15:34:42 katarynka go-librespot[13305]: time="2026-03-24T15:34:42+01:00" level=debug msg="obtained new client token: AADD+oKzmFlQRWog3GMip6KUMqLz8PfZIUTN7sKT0JZHq9kgGKKoZIEW6OYzKO4+rV8WHagCWo8TS6yL6YZqKI2sGjbcX1UpB2TvWdRFATW6VcGrjHxkgML5y7AYKjrkNi1f2zIwDBuaoEYYiYzQRmbnWxSJgG+1e50xwNEEiZ42I+JQtOZoZ5xCND1VHzP0mf5nLUzU/sOfY8UBNFEnVcssUJtYB5m6CdsxCIuIjENoeDYzwe5LLbkn0rQ=" Mar 24 15:34:42 katarynka volumio[13072]: info: Starting Shairport Sync Mar 24 15:34:43 katarynka sudo[13324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:34:43 katarynka sudo[13324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:43 katarynka go-librespot[13305]: time="2026-03-24T15:34:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:43 katarynka sudo[13326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:34:43 katarynka sudo[13326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:43 katarynka go-librespot[13305]: time="2026-03-24T15:34:43+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:43 katarynka go-librespot[13305]: time="2026-03-24T15:34:43+01:00" level=debug msg="completed challenge" Mar 24 15:34:43 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 15:34:43 katarynka go-librespot[13305]: time="2026-03-24T15:34:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:43 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 15:34:43 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:43 katarynka systemd[1]: shairport-sync.service: Consumed 2.336s CPU time. Mar 24 15:34:43 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:43 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:43 katarynka sudo[13329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:34:43 katarynka sudo[13329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:43 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:43 katarynka sudo[13331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 15:34:43 katarynka sudo[13331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:43 katarynka sudo[13324]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:43 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 15:34:43 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 15:34:43 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:43 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:43 katarynka sudo[13326]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:43 katarynka sudo[13331]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:43 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 15:34:43 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 15:34:43 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:43 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:34:43 katarynka sudo[13329]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:43 katarynka volumio[13072]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 15:34:44 katarynka volumio[13072]: info: Upmpdcli Daemon Started Mar 24 15:34:44 katarynka volumio[13072]: info: Shairport-Sync Started Mar 24 15:34:44 katarynka volumio[13072]: Error adding Membership: Error: addMembership EINVAL Mar 24 15:34:44 katarynka volumio[13072]: info: Shairport-Sync Started Mar 24 15:34:44 katarynka volumio[13072]: info: Shairport-Sync Started Mar 24 15:34:44 katarynka volumio[13072]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:44 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:45 katarynka volumio[13072]: info: go-librespot daemon successfully initialized Mar 24 15:34:46 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 15:34:46 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:46 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:46 katarynka go-librespot[13372]: go-librespot daemon starting... Mar 24 15:34:46 katarynka go-librespot[13373]: time="2026-03-24T15:34:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:46 katarynka go-librespot[13373]: time="2026-03-24T15:34:46+01:00" level=debug msg="app state loaded" Mar 24 15:34:46 katarynka go-librespot[13373]: time="2026-03-24T15:34:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:46 katarynka go-librespot[13373]: time="2026-03-24T15:34:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:46 katarynka go-librespot[13373]: time="2026-03-24T15:34:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 15:34:46 katarynka go-librespot[13373]: time="2026-03-24T15:34:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 15:34:46 katarynka go-librespot[13373]: time="2026-03-24T15:34:46+01:00" level=info msg="zeroconf server listening on port 42579" Mar 24 15:34:47 katarynka mpd[13271]: 2026-03-24T15:34:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 15:34:47 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 15:34:47 katarynka sudo[13240]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:47 katarynka sudo[13230]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:47 katarynka volumio[13072]: info: Completed starting Core Plugins Mar 24 15:34:47 katarynka volumio[13072]: info: ------------------------------------------- Mar 24 15:34:47 katarynka volumio[13072]: info: ----- MyVolumio plugins startup ---- Mar 24 15:34:47 katarynka volumio[13072]: info: ------------------------------------------- Mar 24 15:34:47 katarynka volumio[13072]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 15:34:47 katarynka go-librespot[13373]: time="2026-03-24T15:34:47+01:00" level=debug msg="obtained new client token: AAA9y+LvFcisJWIH4g7dQ2XSQ9K+GX2xG9EfKnwyQbPZcVHQ9CCQGvmFLG1MU/ElNSISUQEhx98JLtSz/C2yQjBEaLmxDqCu1E1tJz0YtX8LIHVMnC2fOWW7j4oWxD24KPfpUt0/EzQ0zSJH1t8DEwtXMPVxZp3uId4U1H1WvygoiYLgHOZr6Wp1xPVbVu4wyWEVrzc8ZUWpNYIEMM/EeHxlyEca15Pej4oJSP3qTWlhOEohelNrQVdb" Mar 24 15:34:47 katarynka go-librespot[13373]: time="2026-03-24T15:34:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:47 katarynka go-librespot[13373]: time="2026-03-24T15:34:47+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:47 katarynka go-librespot[13373]: time="2026-03-24T15:34:47+01:00" level=debug msg="completed challenge" Mar 24 15:34:47 katarynka volumio[13072]: error: MPD error: The expression evaluated to a falsy value: Mar 24 15:34:47 katarynka volumio[13072]: assert.ok(self.idling) Mar 24 15:34:47 katarynka volumio[13072]: error: The expression evaluated to a falsy value: Mar 24 15:34:47 katarynka volumio[13072]: assert.ok(self.idling) Mar 24 15:34:47 katarynka volumio[13072]: error: updateQueue error: null Mar 24 15:34:47 katarynka volumio[13072]: info: MPD running with PID13271 Mar 24 15:34:47 katarynka volumio[13072]: ,establishing connection Mar 24 15:34:47 katarynka volumio[13072]: error: updateQueue error: null Mar 24 15:34:47 katarynka go-librespot[13373]: time="2026-03-24T15:34:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:47 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:47 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:48 katarynka volumio[13072]: info: Initializing connection to go-librespot Websocket Mar 24 15:34:48 katarynka volumio[13072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:34:50 katarynka sudo[13402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 15:34:50 katarynka sudo[13402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:50 katarynka sudo[13404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 15:34:50 katarynka sudo[13404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:50 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 15:34:50 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 15:34:50 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 15:34:50 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 15:34:50 katarynka sudo[13404]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:50 katarynka sudo[13402]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:50 katarynka mpd_monitor.sh[13407]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 15:34:50 katarynka volumio[13072]: info: Successfully started MPD Monitor Mar 24 15:34:50 katarynka volumio[13072]: info: Successfully started MPD Monitor Mar 24 15:34:50 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 15:34:50 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:50 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:50 katarynka go-librespot[13411]: go-librespot daemon starting... Mar 24 15:34:50 katarynka go-librespot[13412]: time="2026-03-24T15:34:50+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:50 katarynka go-librespot[13412]: time="2026-03-24T15:34:50+01:00" level=debug msg="app state loaded" Mar 24 15:34:50 katarynka go-librespot[13412]: time="2026-03-24T15:34:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:50 katarynka go-librespot[13412]: time="2026-03-24T15:34:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:34:50 katarynka go-librespot[13412]: time="2026-03-24T15:34:50+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:34:50 katarynka go-librespot[13412]: time="2026-03-24T15:34:50+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:34:50 katarynka go-librespot[13412]: time="2026-03-24T15:34:50+01:00" level=info msg="zeroconf server listening on port 39389" Mar 24 15:34:51 katarynka go-librespot[13412]: time="2026-03-24T15:34:51+01:00" level=debug msg="obtained new client token: AAAjL7afXcOCTv5VNftEHf9LxBDGKeLUQUAiM4wMi7qTQCT+4tINlCGrnN5Q0nu8z83FdAMDvFjAhokZOpHv3LP+shX2by43GbuDQLDaVgYaDiC8v6c2pGTNXiqQrIoSDW/0YJOUPNPKMBQTw0MYjyp+/bgGq8zIdubV//9QnCTyOejCLH1a71wxeShv4eoxnp5InTv4kJsAObVu5CZXmDNRwaXh4JFjpCJNMPTt0W7sQHROC6OKyP4F" Mar 24 15:34:51 katarynka go-librespot[13412]: time="2026-03-24T15:34:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:51 katarynka go-librespot[13412]: time="2026-03-24T15:34:51+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:51 katarynka go-librespot[13412]: time="2026-03-24T15:34:51+01:00" level=debug msg="completed challenge" Mar 24 15:34:51 katarynka go-librespot[13412]: time="2026-03-24T15:34:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:51 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:51 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:51 katarynka volumio[13072]: info: Initializing connection to go-librespot Websocket Mar 24 15:34:51 katarynka volumio[13072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:34:52 katarynka volumio[13072]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 15:34:54 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 24 15:34:54 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:54 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:54 katarynka go-librespot[13419]: go-librespot daemon starting... Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=debug msg="app state loaded" Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:54 katarynka volumio[13072]: info: Initializing connection to go-librespot Websocket Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=debug msg="new websocket client" Mar 24 15:34:54 katarynka volumio[13072]: info: Connection to go-librespot Websocket established Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:34:54 katarynka go-librespot[13420]: time="2026-03-24T15:34:54+01:00" level=info msg="zeroconf server listening on port 35407" Mar 24 15:34:55 katarynka go-librespot[13420]: time="2026-03-24T15:34:55+01:00" level=debug msg="obtained new client token: AABH6vQwTgzvUYtedLQYO0FGbNElwjJVMLq9uO3tUCblf5L2kRORKBle3SI3QN0x90i532lilEMZbUc+zl+cRM7f0P7dCi9HWtqnHmyq53xMgRp+s7nWtuis1XcGqrR7Wu0/FimgP61gOyXNbYyS8Co7VwpHB6Fb1jQthDGkcRx78BHYzSwtXsUxgs9Hto+NZgFxLYyxdEODdrgN3nE2/vkFIeeT/yW03NkRrAtnfYQkq4bZdPEHuHEC" Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 15:34:55 katarynka volumio[13072]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 15:34:55 katarynka volumio[13072]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 15:34:55 katarynka volumio[13072]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 15:34:55 katarynka volumio[13072]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 15:34:55 katarynka go-librespot[13420]: time="2026-03-24T15:34:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:34:55 katarynka volumio[13072]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 15:34:55 katarynka volumio[13072]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 15:34:55 katarynka volumio[13072]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 15:34:55 katarynka volumio[13072]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 15:34:55 katarynka go-librespot[13420]: time="2026-03-24T15:34:55+01:00" level=debug msg="completed keyexchange" Mar 24 15:34:55 katarynka go-librespot[13420]: time="2026-03-24T15:34:55+01:00" level=debug msg="completed challenge" Mar 24 15:34:56 katarynka go-librespot[13420]: time="2026-03-24T15:34:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:34:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:34:56 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:34:57 katarynka volumio[13072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 15:34:57 katarynka volumio[13072]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 15:34:57 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:57 katarynka volumio[13072]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:34:57 katarynka volumio[13072]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 15:34:57 katarynka volumio[13072]: info: MyVolumio login type: Token Mar 24 15:34:57 katarynka volumio[13072]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 15:34:57 katarynka volumio[13072]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 15:34:59 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 24 15:34:59 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:59 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:34:59 katarynka go-librespot[13428]: go-librespot daemon starting... Mar 24 15:34:59 katarynka volumio[13072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 15:34:59 katarynka volumio[13072]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 15:34:59 katarynka volumio[13072]: info: Streaming services startup Mar 24 15:34:59 katarynka volumio[13072]: info: Starting Streaming Daemon Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01:00" level=debug msg="app state loaded" Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:34:59 katarynka sudo[13437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 15:34:59 katarynka sudo[13437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:34:59 katarynka volumio[13072]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 15:34:59 katarynka sudo[13437]: pam_unix(sudo:session): session closed for user root Mar 24 15:34:59 katarynka volumio[13072]: info: Getting Spotify volume Mar 24 15:34:59 katarynka volumio[13072]: info: Connection to go-librespot Websocket closed Mar 24 15:34:59 katarynka volumio[13072]: error: Cannot start Volumio Streaming Daemon Mar 24 15:34:59 katarynka volumio[13072]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 15:34:59 katarynka volumio[13072]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 15:34:59 katarynka volumio[13072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01: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]" Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01: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]" Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01:00" level=info msg="zeroconf server listening on port 43099" Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01:00" level=debug msg="obtained new client token: AACUxEchXcR0/onG9QGpWVzWFihrh8xMUCbTDbrt45Na8ZWcsrqQvba/E3fGYk9zCvuOI6t2j4dfGZVkhaAT1GI5Dev0lSqru1gtguf2nE1A3Z7s/prVOkq/tPKX1BKihGaerOyO39+9DErEXUeaT+huqfrPbBSgK18pC+liflnLk54BWfPCVS/Xbi5T07jIvSUGGcq9R+DmIdHWsOwNGlqUorQp9zFPjBdc7+G7o8aveYSa15RamzMLDag=" Mar 24 15:34:59 katarynka volumio[13072]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:59 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:59 katarynka volumio[13072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 24 15:34:59 katarynka volumio[13072]: SPOTIFY: SPOTIFY VOLUME undefined Mar 24 15:34:59 katarynka volumio[13072]: SPOTIFY: VOLUMIO VOLUME 96 Mar 24 15:34:59 katarynka volumio[13072]: info: Aligning Spotify Volume to Volumio Volume Mar 24 15:34:59 katarynka volumio[13072]: info: CoreCommandRouter::volumioGetState Mar 24 15:34:59 katarynka volumio[13072]: info: CorePlayQueue::getTrack 0 Mar 24 15:34:59 katarynka volumio[13072]: info: Setting Spotify Volume from Volumio: 96 Mar 24 15:34:59 katarynka go-librespot[13429]: time="2026-03-24T15:34:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:00 katarynka go-librespot[13429]: time="2026-03-24T15:35:00+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:00 katarynka go-librespot[13429]: time="2026-03-24T15:35:00+01:00" level=debug msg="completed challenge" Mar 24 15:35:00 katarynka go-librespot[13429]: time="2026-03-24T15:35:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:00 katarynka volumio[13072]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 15:35:00 katarynka volumio[13072]: Error: socket hang up Mar 24 15:35:00 katarynka volumio[13072]: at connResetException (node:internal/errors:720:14) Mar 24 15:35:00 katarynka volumio[13072]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 24 15:35:00 katarynka volumio[13072]: at Socket.emit (node:events:526:35) Mar 24 15:35:00 katarynka volumio[13072]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 24 15:35:00 katarynka volumio[13072]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 24 15:35:00 katarynka volumio[13072]: code: 'ECONNRESET', Mar 24 15:35:00 katarynka volumio[13072]: response: undefined Mar 24 15:35:00 katarynka volumio[13072]: } Mar 24 15:35:00 katarynka volumio[13072]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 15:35:01 katarynka sudo[13471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 15:34' Mar 24 15:35:01 katarynka sudo[13471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:02 katarynka sudo[13471]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:02 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:02 katarynka volumio-remote-updater[622]: [2026-03-24 15:35:02] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 15:35:02 katarynka volumio-remote-updater[622]: [2026-03-24 15:35:02] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 15:35:02 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 15:35:02 katarynka systemd[1]: volumio.service: Consumed 49.401s CPU time. Mar 24 15:35:02 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 15:35:02 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 15:35:02 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 25041. Mar 24 15:35:02 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 15:35:02 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 15:35:02 katarynka systemd[1]: volumio.service: Consumed 49.401s CPU time. Mar 24 15:35:02 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 15:35:02 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 15:35:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 24 15:35:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:03 katarynka go-librespot[13499]: go-librespot daemon starting... Mar 24 15:35:03 katarynka go-librespot[13500]: time="2026-03-24T15:35:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:03 katarynka go-librespot[13500]: time="2026-03-24T15:35:03+01:00" level=debug msg="app state loaded" Mar 24 15:35:03 katarynka go-librespot[13500]: time="2026-03-24T15:35:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:03 katarynka go-librespot[13500]: time="2026-03-24T15:35:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:35:03 katarynka go-librespot[13500]: time="2026-03-24T15:35:03+01: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]" Mar 24 15:35:03 katarynka go-librespot[13500]: time="2026-03-24T15:35:03+01: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]" Mar 24 15:35:03 katarynka go-librespot[13500]: time="2026-03-24T15:35:03+01:00" level=info msg="zeroconf server listening on port 35069" Mar 24 15:35:04 katarynka go-librespot[13500]: time="2026-03-24T15:35:04+01:00" level=debug msg="obtained new client token: AAD4OXM7v7KjxVtCnR2iqjW2DtdQ6Ru5ruELvG1c8+XVjav1RB0EzEcPASf0ZOr9Oru5mNotnSuoq80Ai6EOoNjWMXjMrSMZ8noUPQsQhC3Heu3r290gmfsc37cnBX733JZ4V4w8WE0tu5z8BDVK54flONw4+cuTRKksRsWvN08toq8sDNMQu/8QA/QlnXovgX39oMxfEGCh8XioyosvXeuSGRY5uGNJOrYathX651pZSh6M47BUBIkN" Mar 24 15:35:04 katarynka go-librespot[13500]: time="2026-03-24T15:35:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:04 katarynka go-librespot[13500]: time="2026-03-24T15:35:04+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:04 katarynka go-librespot[13500]: time="2026-03-24T15:35:04+01:00" level=debug msg="completed challenge" Mar 24 15:35:04 katarynka go-librespot[13500]: time="2026-03-24T15:35:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:06 katarynka volumio[13483]: info: ------------------------------------------- Mar 24 15:35:06 katarynka volumio[13483]: info: ----- Volumio3 ---- Mar 24 15:35:06 katarynka volumio[13483]: info: ------------------------------------------- Mar 24 15:35:06 katarynka volumio[13483]: info: ----- System startup ---- Mar 24 15:35:06 katarynka volumio[13483]: info: ------------------------------------------- Mar 24 15:35:07 katarynka volumio-remote-updater[622]: [2026-03-24 15:35:07] [connect] Successful connection Mar 24 15:35:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 24 15:35:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:07 katarynka go-librespot[13513]: go-librespot daemon starting... Mar 24 15:35:07 katarynka go-librespot[13514]: time="2026-03-24T15:35:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:07 katarynka go-librespot[13514]: time="2026-03-24T15:35:07+01:00" level=debug msg="app state loaded" Mar 24 15:35:07 katarynka go-librespot[13514]: time="2026-03-24T15:35:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:07 katarynka volumio[13483]: info: MYVOLUMIO Environment detected Mar 24 15:35:07 katarynka volumio[13483]: info: Plugin folders cleanup Mar 24 15:35:07 katarynka volumio[13483]: info: Scanning into folder /volumio/app/plugins/ Mar 24 15:35:07 katarynka go-librespot[13514]: time="2026-03-24T15:35:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:35:07 katarynka go-librespot[13514]: time="2026-03-24T15:35:07+01: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]" Mar 24 15:35:07 katarynka go-librespot[13514]: time="2026-03-24T15:35:07+01: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]" Mar 24 15:35:07 katarynka volumio[13483]: info: Scanning category audio_interface Mar 24 15:35:07 katarynka volumio[13483]: info: Scanning category miscellanea Mar 24 15:35:07 katarynka volumio[13483]: info: Scanning category music_service Mar 24 15:35:08 katarynka volumio[13483]: info: Scanning category plugins.json Mar 24 15:35:08 katarynka volumio[13483]: info: Scanning category system_controller Mar 24 15:35:08 katarynka go-librespot[13514]: time="2026-03-24T15:35:08+01:00" level=info msg="zeroconf server listening on port 45239" Mar 24 15:35:08 katarynka volumio[13483]: info: Scanning category user_interface Mar 24 15:35:08 katarynka volumio[13483]: info: Scanning into folder /data/plugins/ Mar 24 15:35:08 katarynka volumio[13483]: info: Scanning category music_service Mar 24 15:35:08 katarynka volumio[13483]: info: Plugin folders cleanup completed Mar 24 15:35:08 katarynka volumio[13483]: info: ------------------------------------------- Mar 24 15:35:08 katarynka volumio[13483]: info: ----- Core plugins startup ---- Mar 24 15:35:08 katarynka volumio[13483]: info: ------------------------------------------- Mar 24 15:35:08 katarynka volumio[13483]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 15:35:08 katarynka volumio[13483]: info: Adding plugin upnp to MyMusic Plugins Mar 24 15:35:08 katarynka volumio[13483]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 15:35:08 katarynka volumio[13483]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 15:35:08 katarynka volumio[13483]: info: Loading plugins from folder /data/plugins/ Mar 24 15:35:08 katarynka volumio[13483]: info: Loading plugin "system"... Mar 24 15:35:08 katarynka volumio[13483]: info: Loading plugin "appearance"... Mar 24 15:35:08 katarynka go-librespot[13514]: time="2026-03-24T15:35:08+01:00" level=debug msg="obtained new client token: AAD6vjZbzRub0EIWHsX7jLw9L4z0K5xlCFCsCpLZDAR8MNFvzEuBNwyWcxAaUCWfW8UwqBb8CQkoJJQoaqjbwujwRxp3V6lVsUIq3omsd1QGw0+2KuDLxzexIPUJKz/7XBs6AQQ1l1sL56fr8ife/PKFbcsTeiYUhhceccpbkq3mIsQkLJZfRWjNCwBv2rooqfFIxg+2u2/urYAUKpKUTWn/Pij3QuT23NAhQD/0yktiEnm5tEiZXSsW" Mar 24 15:35:08 katarynka go-librespot[13514]: time="2026-03-24T15:35:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:08 katarynka go-librespot[13514]: time="2026-03-24T15:35:08+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:08 katarynka go-librespot[13514]: time="2026-03-24T15:35:08+01:00" level=debug msg="completed challenge" Mar 24 15:35:08 katarynka go-librespot[13514]: time="2026-03-24T15:35:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "network"... Mar 24 15:35:10 katarynka volumio[13483]: info: Refreshing Cached IP Addresses Mar 24 15:35:10 katarynka sudo[13529]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 15:35:10 katarynka sudo[13529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "services"... Mar 24 15:35:10 katarynka sudo[13531]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 15:35:10 katarynka sudo[13531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:10 katarynka sudo[13529]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "alsa_controller"... Mar 24 15:35:10 katarynka sudo[13531]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:10 katarynka sudo[13539]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 15:35:10 katarynka sudo[13539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:10 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "wizard"... Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "networkfs"... Mar 24 15:35:10 katarynka volumio[13483]: info: Starting Udev Watcher for removable devices Mar 24 15:35:10 katarynka volumio[13483]: info: Ignoring mount for partition: boot Mar 24 15:35:10 katarynka volumio[13483]: info: Ignoring mount for partition: volumio Mar 24 15:35:10 katarynka volumio[13483]: info: Ignoring mount for partition: volumio_data Mar 24 15:35:10 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "volumio_command_line_client"... Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "upnp"... Mar 24 15:35:10 katarynka volumio[13483]: info: [1774362910572] Starting Upmpd Daemon Mar 24 15:35:10 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "my_music"... Mar 24 15:35:10 katarynka volumio[13483]: info: Loading plugin "mpd"... Mar 24 15:35:11 katarynka sudo[13539]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:11 katarynka volumio[13483]: info: Loading plugin "upnp_browser"... Mar 24 15:35:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 24 15:35:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:11 katarynka go-librespot[13565]: go-librespot daemon starting... Mar 24 15:35:11 katarynka go-librespot[13566]: time="2026-03-24T15:35:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:11 katarynka go-librespot[13566]: time="2026-03-24T15:35:11+01:00" level=debug msg="app state loaded" Mar 24 15:35:11 katarynka go-librespot[13566]: time="2026-03-24T15:35:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:11 katarynka go-librespot[13566]: time="2026-03-24T15:35:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:35:11 katarynka go-librespot[13566]: time="2026-03-24T15:35:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:35:11 katarynka go-librespot[13566]: time="2026-03-24T15:35:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:35:11 katarynka go-librespot[13566]: time="2026-03-24T15:35:11+01:00" level=info msg="zeroconf server listening on port 41381" Mar 24 15:35:12 katarynka go-librespot[13566]: time="2026-03-24T15:35:12+01:00" level=debug msg="obtained new client token: AAA3hkjsELOOSfIWdohv2aKfqL11rqHI/RECTmCyrwakvbNsIdqb8hRS1aogzKGnJDO0HK4Tz9RuVCZrkD9BpWdm7MRtxm4Pgk5CLBZGXeb9fgfOOcwLzsdoxIu5Nw2rOD2sKk8NIdOIK41qICd4ee3RgT8UAOJjAlKnQzB7mqg0Xvpo+ZXa74L8HUuAzyVkb4pBI43BIekE+XLLdHTjXWxE06Df49dSLAxRfLvpI0M3MBNioDoRm5py" Mar 24 15:35:12 katarynka go-librespot[13566]: time="2026-03-24T15:35:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:12 katarynka go-librespot[13566]: time="2026-03-24T15:35:12+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:12 katarynka go-librespot[13566]: time="2026-03-24T15:35:12+01:00" level=debug msg="completed challenge" Mar 24 15:35:12 katarynka go-librespot[13566]: time="2026-03-24T15:35:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:14 katarynka volumio[13483]: info: Starting UPNP Browser Mar 24 15:35:14 katarynka volumio[13483]: info: Loading plugin "alarm-clock"... Mar 24 15:35:14 katarynka volumio[13483]: info: Loading plugin "airplay_emulation"... Mar 24 15:35:14 katarynka volumio[13483]: info: Starting Shairport Sync Mar 24 15:35:14 katarynka volumio[13483]: info: Loading plugin "last_100"... Mar 24 15:35:14 katarynka volumio[13483]: info: Loading plugin "webradio"... Mar 24 15:35:14 katarynka volumio[13483]: info: Loading plugin "i2s_dacs"... Mar 24 15:35:14 katarynka volumio[13483]: info: Loading plugin "volumiodiscovery"... Mar 24 15:35:14 katarynka volumio[13483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 15:35:14 katarynka volumio[13483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:35:14 katarynka volumio[13483]: *** WARNING *** For more information see Mar 24 15:35:14 katarynka volumio[13483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 15:35:14 katarynka volumio[13483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:35:14 katarynka volumio[13483]: *** WARNING *** For more information see Mar 24 15:35:14 katarynka node[13483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 15:35:14 katarynka node[13483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:35:14 katarynka node[13483]: *** WARNING *** For more information see Mar 24 15:35:14 katarynka node[13483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 15:35:14 katarynka node[13483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 15:35:14 katarynka node[13483]: *** WARNING *** For more information see Mar 24 15:35:14 katarynka volumio[13483]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 15:35:14 katarynka volumio[13483]: info: Discovery: Started advertising with name: katarynka Mar 24 15:35:15 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 15:35:15 katarynka volumio[13483]: info: Loading plugin "spop"... Mar 24 15:35:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 24 15:35:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:15 katarynka go-librespot[13575]: go-librespot daemon starting... Mar 24 15:35:15 katarynka go-librespot[13576]: time="2026-03-24T15:35:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:15 katarynka go-librespot[13576]: time="2026-03-24T15:35:15+01:00" level=debug msg="app state loaded" Mar 24 15:35:15 katarynka go-librespot[13576]: time="2026-03-24T15:35:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:15 katarynka go-librespot[13576]: time="2026-03-24T15:35:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:35:15 katarynka go-librespot[13576]: time="2026-03-24T15:35:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:35:15 katarynka go-librespot[13576]: time="2026-03-24T15:35:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:35:16 katarynka go-librespot[13576]: time="2026-03-24T15:35:16+01:00" level=info msg="zeroconf server listening on port 43259" Mar 24 15:35:16 katarynka go-librespot[13576]: time="2026-03-24T15:35:16+01:00" level=debug msg="obtained new client token: AAAI8DQDlmEusr8y6+/UGSbh9mOaHyia1nbyy3i3RyB6rX31ziSwnWaTzXGe0LvqDwecykDtMBEvM4S6U2cFF86KAWxPZ0v5xflIBFpll5pi2JQkjW65aRI+qo1eIdSkzZqnOobigi/ho0PLTBKMBJjsT6N/qA5DsTbhihFRq9vt/4OBYeZS3bKy9O9EWowV+/XpWz55gL17cLMjnpiBIDngBMR+MUlotwfFrbsnj7rkaWM/dXCgYHPe" Mar 24 15:35:16 katarynka go-librespot[13576]: time="2026-03-24T15:35:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:16 katarynka go-librespot[13576]: time="2026-03-24T15:35:16+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:16 katarynka go-librespot[13576]: time="2026-03-24T15:35:16+01:00" level=debug msg="completed challenge" Mar 24 15:35:16 katarynka go-librespot[13576]: time="2026-03-24T15:35:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:17 katarynka volumio[13483]: info: Loading plugin "outputs"... Mar 24 15:35:17 katarynka volumio[13483]: info: Loading plugin "albumart"... Mar 24 15:35:17 katarynka volumio[13483]: info: Plugin example_plugin is not enabled Mar 24 15:35:17 katarynka volumio[13483]: info: Loading plugin "inputs"... Mar 24 15:35:17 katarynka volumio[13483]: info: Loading plugin "updater_comm"... Mar 24 15:35:17 katarynka volumio[13483]: info: Plugin mpdemulation is not enabled Mar 24 15:35:17 katarynka volumio[13483]: info: Loading plugin "rest_api"... Mar 24 15:35:17 katarynka volumio[13483]: info: Loading plugin "websocket"... Mar 24 15:35:17 katarynka volumio[13483]: info: Starting Socket.io Server version 1.7.4 Mar 24 15:35:17 katarynka volumio[13483]: info: Loading i18n strings for locale pl Mar 24 15:35:17 katarynka volumio[13483]: Updating browse sources language Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::initPlayerControls Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 15:35:17 katarynka volumio[13483]: Express server listening on port 3000 Mar 24 15:35:17 katarynka volumio[13483]: [Metrics] WebUI: 12s 475.81ms Mar 24 15:35:17 katarynka volumio[13483]: info: CoreStateMachine::resetVolumioState Mar 24 15:35:17 katarynka volumio[13483]: info: CoreStateMachine::getcurrentVolume Mar 24 15:35:17 katarynka volumio[13483]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 15:35:17 katarynka volumio[13483]: info: Cannot read play queue from file Mar 24 15:35:17 katarynka volumio[13483]: info: Volumio Network Manager: Network status updated: 2 Mar 24 15:35:18 katarynka volumio[13583]: Forking 3 albumart workers Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:18 katarynka volumio[13483]: info: CoreStateMachine::setRepeat null single undefined Mar 24 15:35:18 katarynka volumio[13483]: info: CoreStateMachine::pushState Mar 24 15:35:18 katarynka volumio[13483]: info: CorePlayQueue::getTrack 0 Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::volumioPushState Mar 24 15:35:18 katarynka volumio[13483]: info: CoreStateMachine::setRandom null Mar 24 15:35:18 katarynka volumio[13483]: info: CoreStateMachine::pushState Mar 24 15:35:18 katarynka volumio[13483]: info: CorePlayQueue::getTrack 0 Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::volumioPushState Mar 24 15:35:18 katarynka volumio[13483]: info: Setting Device type: Raspberry PI Mar 24 15:35:18 katarynka volumio[13483]: info: Completed loading Core Plugins Mar 24 15:35:18 katarynka volumio[13483]: info: Preparing to generate the ALSA configuration file Mar 24 15:35:18 katarynka volumio[13483]: info: VolumeController:: Volume=96 Mute =false Mar 24 15:35:18 katarynka volumio[13483]: info: CoreStateMachine::pushState Mar 24 15:35:18 katarynka volumio[13483]: info: CorePlayQueue::getTrack 0 Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::volumioPushState Mar 24 15:35:18 katarynka volumio[13483]: info: CoreStateMachine::updateTrackBlock Mar 24 15:35:18 katarynka volumio[13483]: info: CorePlayQueue::getTrackBlock Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 15:35:18 katarynka volumio[13483]: info: Asound.conf file unchanged, so no further update is needed Mar 24 15:35:18 katarynka volumio[13483]: info: Output device has changed, restarting MPD Mar 24 15:35:18 katarynka volumio[13483]: info: Output device has changed, restarting Shairport Sync Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:18 katarynka sudo[13640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 15:35:18 katarynka sudo[13640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:18 katarynka volumio[13483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 15:35:18 katarynka volumio[13483]: info: ___________ START PLUGINS ___________ Mar 24 15:35:18 katarynka sudo[13640]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:18 katarynka volumio[13483]: info: ControllerMpd::onStart: Initializing MPD Mar 24 15:35:18 katarynka volumio[13483]: info: Creating MPD Configuration file Mar 24 15:35:18 katarynka sudo[13642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 15:35:18 katarynka sudo[13642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 15:35:18 katarynka volumio[13483]: info: [1774362918835] CoreMusicLibrary::Adding element Serwery Mediów Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:35:18 katarynka sudo[13651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 15:35:18 katarynka volumio[13483]: info: UPNP Browser: Client initialized successfully Mar 24 15:35:18 katarynka sudo[13651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:18 katarynka sudo[13652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 15:35:18 katarynka sudo[13651]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:18 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 15:35:18 katarynka sudo[13652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:18 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:19 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 15:35:19 katarynka volumio[13483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:19 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 15:35:19 katarynka systemd[1]: mpd.service: Consumed 7.762s CPU time. Mar 24 15:35:19 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 15:35:19 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 15:35:19 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 15:35:19 katarynka volumio[13483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 15:35:19 katarynka volumio[13483]: info: [1774362919157] CoreMusicLibrary::Adding element Last_100 Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 15:35:19 katarynka volumio[13483]: info: [1774362919189] CoreMusicLibrary::Adding element Webradio Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 15:35:19 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 15:35:19 katarynka volumio[13483]: info: Initializing BBC Radios Mar 24 15:35:19 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 15:35:19 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 15:35:19 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 15:35:19 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 15:35:19 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 15:35:19 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 15:35:19 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 15:35:19 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 15:35:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 24 15:35:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:19 katarynka go-librespot[13680]: go-librespot daemon starting... Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:19 katarynka go-librespot[13681]: time="2026-03-24T15:35:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:19 katarynka go-librespot[13681]: time="2026-03-24T15:35:19+01:00" level=debug msg="app state loaded" Mar 24 15:35:19 katarynka go-librespot[13681]: time="2026-03-24T15:35:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:19 katarynka volumio[13483]: info: Creating Spotify config file Mar 24 15:35:19 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:19 katarynka volumio-remote-updater[622]: [2026-03-24 15:35:19] [connect] Successful connection Mar 24 15:35:19 katarynka sudo[13671]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 15:35:19 katarynka sudo[13671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 15:35:19 katarynka sudo[13671]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01: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]" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01: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]" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01:00" level=info msg="zeroconf server listening on port 44987" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01:00" level=debug msg="obtained new client token: AAADXa0v4UqKHApC496+0mHflo//DJ27VxQjkeF2VS4Cb6KMLnNjfR/JmRXZroONPz63ABsSqt+HopK57FTb3v6sNaxn5IuCQlCNRw3FInZKjQj9ppRujmxEWxHn3vcOj5jENp7C2JDRsB763zYsxqBIDkCHkAWFjwqzi2KsA7IknZrGumgsuLTiQcd59dldLmJrZkOtHFOb0lGpA22ITAkfRFX/0PGQjPeoABxQsFNW6OSY8rra1m9h4ro=" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01: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" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 15:35:20 katarynka volumio[13483]: info: Volumio Calling Home Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01:00" level=debug msg="completed challenge" Mar 24 15:35:20 katarynka go-librespot[13681]: time="2026-03-24T15:35:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:21 katarynka volumio[13483]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 15:35:21 katarynka volumio[13483]: info: Discovery: Found device katarynka Mar 24 15:35:21 katarynka volumio[13483]: info: CoreCommandRouter::volumioGetState Mar 24 15:35:21 katarynka volumio[13483]: info: CorePlayQueue::getTrack 0 Mar 24 15:35:21 katarynka sudo[13710]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 15:35:21 katarynka volumio[13483]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 15:35:21 katarynka sudo[13710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:21 katarynka volumio[13483]: info: Discovery: Found device katarynka Mar 24 15:35:21 katarynka volumio[13483]: info: CoreCommandRouter::volumioGetState Mar 24 15:35:21 katarynka sudo[13711]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 15:35:21 katarynka sudo[13710]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:21 katarynka volumio[13483]: info: CorePlayQueue::getTrack 0 Mar 24 15:35:21 katarynka sudo[13711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:21 katarynka sudo[13711]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:21 katarynka volumio[13483]: info: MPD Permissions set Mar 24 15:35:21 katarynka volumio[13483]: info: MPD Permissions set Mar 24 15:35:21 katarynka volumio[13483]: info: VolumeController:: Volume=96 Mute =false Mar 24 15:35:21 katarynka volumio[13483]: info: CoreStateMachine::pushState Mar 24 15:35:21 katarynka volumio[13483]: info: CorePlayQueue::getTrack 0 Mar 24 15:35:21 katarynka volumio[13483]: info: CoreCommandRouter::volumioPushState Mar 24 15:35:21 katarynka volumio-remote-updater[622]: [2026-03-24 15:35:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774362919 101 Mar 24 15:35:21 katarynka volumio[13483]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 24 15:35:21 katarynka volumio[13483]: info: Volumio called home Mar 24 15:35:21 katarynka volumio[13483]: info: Spotify config file written Mar 24 15:35:22 katarynka sudo[13715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 15:35:22 katarynka sudo[13715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:22 katarynka volumio[13483]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 15:35:22 katarynka volumio[13483]: info: No need to fix Spotify hosts Mar 24 15:35:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:22 katarynka go-librespot[13727]: go-librespot daemon starting... Mar 24 15:35:22 katarynka sudo[13715]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:22 katarynka go-librespot[13728]: time="2026-03-24T15:35:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:22 katarynka go-librespot[13728]: time="2026-03-24T15:35:22+01:00" level=debug msg="app state loaded" Mar 24 15:35:22 katarynka go-librespot[13728]: time="2026-03-24T15:35:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:22 katarynka volumio[13483]: info: Starting Shairport Sync Mar 24 15:35:22 katarynka volumio[13483]: info: Starting Shairport Sync Mar 24 15:35:22 katarynka volumio[13483]: info: Starting Shairport Sync Mar 24 15:35:22 katarynka sudo[13740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:35:22 katarynka sudo[13740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:22 katarynka volumio[13607]: Starting albumart workers Mar 24 15:35:22 katarynka go-librespot[13728]: time="2026-03-24T15:35:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:35:22 katarynka go-librespot[13728]: time="2026-03-24T15:35:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 15:35:22 katarynka go-librespot[13728]: time="2026-03-24T15:35:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 15:35:22 katarynka sudo[13738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:35:22 katarynka sudo[13738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:23 katarynka sudo[13742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 15:35:23 katarynka go-librespot[13728]: time="2026-03-24T15:35:23+01:00" level=info msg="zeroconf server listening on port 43477" Mar 24 15:35:23 katarynka sudo[13742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:23 katarynka sudo[13736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 15:35:23 katarynka sudo[13736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:23 katarynka go-librespot[13728]: time="2026-03-24T15:35:23+01:00" level=debug msg="obtained new client token: AAC0wySK9xHBTbXa8UB00wTghPtkAobFiQVUP4jVt4rc5TpInH4Rj5dgaK1ygHQSJRyU3ZboMib7OaLDuVcpQlO1jujqDKe+xInR0ZpFgUseVMlOzC19kzPIQSB3RT0piYwN9ikhMKKDSflKahVfpS01gDXV+Mx8pTL4ph1ekFBtip+lY+cThAyYXEi7fIuUa8C+DX8W7wX7/gLex7H9LECtJNcFk6Qs+AtYKKupgxl7TQsms7aswL2z" Mar 24 15:35:23 katarynka volumio[13606]: Starting albumart workers Mar 24 15:35:23 katarynka go-librespot[13728]: time="2026-03-24T15:35:23+01: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" Mar 24 15:35:23 katarynka go-librespot[13728]: time="2026-03-24T15:35:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 15:35:23 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 15:35:23 katarynka sudo[13742]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:23 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 15:35:23 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:35:23 katarynka systemd[1]: shairport-sync.service: Consumed 2.296s CPU time. Mar 24 15:35:23 katarynka volumio[13605]: Starting albumart workers Mar 24 15:35:23 katarynka go-librespot[13728]: time="2026-03-24T15:35:23+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:23 katarynka go-librespot[13728]: time="2026-03-24T15:35:23+01:00" level=debug msg="completed challenge" Mar 24 15:35:23 katarynka go-librespot[13728]: time="2026-03-24T15:35:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:23 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 15:35:23 katarynka sudo[13740]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:23 katarynka sudo[13738]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:23 katarynka sudo[13736]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:23 katarynka volumio[13483]: info: Upmpdcli Daemon Started Mar 24 15:35:23 katarynka volumio[13483]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 15:35:23 katarynka volumio[13483]: info: Shairport-Sync Started Mar 24 15:35:23 katarynka volumio[13483]: Error adding Membership: Error: addMembership EINVAL Mar 24 15:35:23 katarynka volumio[13483]: info: Shairport-Sync Started Mar 24 15:35:23 katarynka volumio[13483]: info: Shairport-Sync Started Mar 24 15:35:24 katarynka volumio[13483]: info: CoreCommandRouter::volumioGetState Mar 24 15:35:24 katarynka volumio[13483]: info: CorePlayQueue::getTrack 0 Mar 24 15:35:25 katarynka volumio[13483]: info: go-librespot daemon successfully initialized Mar 24 15:35:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 24 15:35:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:26 katarynka go-librespot[13782]: go-librespot daemon starting... Mar 24 15:35:26 katarynka go-librespot[13783]: time="2026-03-24T15:35:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:26 katarynka go-librespot[13783]: time="2026-03-24T15:35:26+01:00" level=debug msg="app state loaded" Mar 24 15:35:26 katarynka go-librespot[13783]: time="2026-03-24T15:35:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=info msg="zeroconf server listening on port 39157" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=debug msg="obtained new client token: AAA2HSGBibF5xpLp8EZZuW0kmEHoMDstPloeIrdif2stetFe7ugva3C8xkmk6ZUWlnjFlqqhkxXcJsF1xlJ/nQ/0SftCy+slkHEaXeYQ3IRzJ2oaTvH7wee6moTTwXTlhyh/n2MfPtXycjDS3eQY7K1sEk6vuZfpQeXK7a+lJxdwY6+osmYeO9wv/pG7CpEcWO5jZjfqvrMAEmIkQ4El3SXbyjneNT+SQeKQg0E83TdwN7OuquHWNCeS788=" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=debug msg="completed challenge" Mar 24 15:35:27 katarynka go-librespot[13783]: time="2026-03-24T15:35:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:27 katarynka mpd[13690]: 2026-03-24T15:35:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 15:35:27 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 15:35:27 katarynka sudo[13652]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:27 katarynka sudo[13642]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:27 katarynka volumio[13483]: info: Completed starting Core Plugins Mar 24 15:35:27 katarynka volumio[13483]: info: ------------------------------------------- Mar 24 15:35:27 katarynka volumio[13483]: info: ----- MyVolumio plugins startup ---- Mar 24 15:35:27 katarynka volumio[13483]: info: ------------------------------------------- Mar 24 15:35:27 katarynka volumio[13483]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 15:35:27 katarynka volumio[13483]: error: MPD error: The expression evaluated to a falsy value: Mar 24 15:35:27 katarynka volumio[13483]: assert.ok(self.idling) Mar 24 15:35:27 katarynka volumio[13483]: error: The expression evaluated to a falsy value: Mar 24 15:35:27 katarynka volumio[13483]: assert.ok(self.idling) Mar 24 15:35:27 katarynka volumio[13483]: error: updateQueue error: null Mar 24 15:35:27 katarynka volumio[13483]: info: MPD running with PID13690 Mar 24 15:35:27 katarynka volumio[13483]: ,establishing connection Mar 24 15:35:28 katarynka volumio[13483]: error: updateQueue error: null Mar 24 15:35:28 katarynka volumio[13483]: info: Initializing connection to go-librespot Websocket Mar 24 15:35:28 katarynka volumio[13483]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:35:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 24 15:35:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:30 katarynka go-librespot[13811]: go-librespot daemon starting... Mar 24 15:35:30 katarynka go-librespot[13812]: time="2026-03-24T15:35:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:30 katarynka go-librespot[13812]: time="2026-03-24T15:35:30+01:00" level=debug msg="app state loaded" Mar 24 15:35:30 katarynka go-librespot[13812]: time="2026-03-24T15:35:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:30 katarynka sudo[13819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 15:35:30 katarynka sudo[13819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:30 katarynka sudo[13821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 15:35:30 katarynka sudo[13821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:30 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 15:35:30 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 15:35:30 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 15:35:31 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 15:35:31 katarynka sudo[13819]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:31 katarynka sudo[13821]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:31 katarynka volumio[13483]: info: Successfully started MPD Monitor Mar 24 15:35:31 katarynka mpd_monitor.sh[13824]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 15:35:31 katarynka volumio[13483]: info: Successfully started MPD Monitor Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=info msg="zeroconf server listening on port 34953" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=debug msg="obtained new client token: AADQExvY28j3HJQzLrLjaYDcVHj1SW4M68alSYuLkh4fPmp4pCIpIpubA5ObaUk0r07+mjFyaap30GDKUfy+MXjYEOaS/YlSJGlir2Z25FzmMZ/E7vCst54pmPxEU6ypo335+nmnITqeWdXQ8tthXjbjVyHShbrn4RiE7x+KCKn0rA0MuezKzfrPayej/VFQ2aPIrOdUqVAoFhikrhKknFnJxoKe+U/Y5SmwToayipPqc1wsyC1HfxVd/lo=" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=debug msg="completed challenge" Mar 24 15:35:31 katarynka go-librespot[13812]: time="2026-03-24T15:35:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:31 katarynka volumio[13483]: info: Initializing connection to go-librespot Websocket Mar 24 15:35:31 katarynka volumio[13483]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:35:32 katarynka volumio[13483]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 15:35:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 24 15:35:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:34 katarynka volumio[13483]: info: Initializing connection to go-librespot Websocket Mar 24 15:35:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:34 katarynka volumio[13483]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:35:34 katarynka go-librespot[13830]: go-librespot daemon starting... Mar 24 15:35:34 katarynka go-librespot[13831]: time="2026-03-24T15:35:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:34 katarynka go-librespot[13831]: time="2026-03-24T15:35:34+01:00" level=debug msg="app state loaded" Mar 24 15:35:34 katarynka go-librespot[13831]: time="2026-03-24T15:35:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=info msg="zeroconf server listening on port 34351" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=debug msg="obtained new client token: AABeNXqCRL51tUKEg1dLu3KE0mD721Gsz9UJ8M+XSblBoXr64VXqhDd9mG3o4zViQ0ekrmEPyQKbVs6Nwd2gtXJmo5orbDEDigXn/BsUxDRKjVsgvY09eD8kbDzSQrQUQ1fA+UZ4mh18Zeb4RdgjTz0KiiVm5aQHzFQ/XzzgePRejbTsWFsyUXUBNID2pjYvtEh6gm7PMBEyGBqbT+j+YUV6GfJxGb3Cw1oZBo9oze7RBU/HawkIIdFOZlk=" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=debug msg="completed challenge" Mar 24 15:35:35 katarynka go-librespot[13831]: time="2026-03-24T15:35:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 15:35:36 katarynka volumio[13483]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 15:35:36 katarynka volumio[13483]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 15:35:36 katarynka volumio[13483]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 15:35:36 katarynka volumio[13483]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 15:35:36 katarynka volumio[13483]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 15:35:36 katarynka volumio[13483]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 15:35:36 katarynka volumio[13483]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 15:35:36 katarynka volumio[13483]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 15:35:38 katarynka volumio[13483]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 15:35:38 katarynka volumio[13483]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 15:35:38 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:38 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:38 katarynka volumio[13483]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 15:35:38 katarynka volumio[13483]: info: MyVolumio login type: Token Mar 24 15:35:38 katarynka volumio[13483]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 15:35:38 katarynka volumio[13483]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 15:35:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 24 15:35:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:38 katarynka go-librespot[13838]: go-librespot daemon starting... Mar 24 15:35:38 katarynka go-librespot[13839]: time="2026-03-24T15:35:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:38 katarynka go-librespot[13839]: time="2026-03-24T15:35:38+01:00" level=debug msg="app state loaded" Mar 24 15:35:38 katarynka go-librespot[13839]: time="2026-03-24T15:35:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:39 katarynka go-librespot[13839]: time="2026-03-24T15:35:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:35:39 katarynka go-librespot[13839]: time="2026-03-24T15:35:39+01: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]" Mar 24 15:35:39 katarynka go-librespot[13839]: time="2026-03-24T15:35:39+01: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]" Mar 24 15:35:39 katarynka go-librespot[13839]: time="2026-03-24T15:35:39+01:00" level=info msg="zeroconf server listening on port 34777" Mar 24 15:35:39 katarynka go-librespot[13839]: time="2026-03-24T15:35:39+01:00" level=debug msg="obtained new client token: AACBM3FhH4xBYfh01HczKMxqnyCnn10RA3Q7xznmVdh5SpqBl6vfOAkxyPFNrHzIUt1SynU+8HhaDyoBF8NkDLjEFbh4VUpz/vrQyjLDgsVtC9rUnxQ0IcfmIbxaR43sE6Ja6KS+7yt5gDgevkAU4jPSC1MAYEIjWWI4l8BHBA7rkRvTrxw4jq1m/ZWd5noMbjPAa7ChGXQ3IZpNTIOTzSfkli4852CnnehXcVnQwWfRZZMfQAK9gfyKjJs=" Mar 24 15:35:39 katarynka go-librespot[13839]: time="2026-03-24T15:35:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:39 katarynka volumio[13483]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 15:35:39 katarynka volumio[13483]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 15:35:39 katarynka volumio[13483]: info: Streaming services startup Mar 24 15:35:39 katarynka volumio[13483]: info: Starting Streaming Daemon Mar 24 15:35:40 katarynka go-librespot[13839]: time="2026-03-24T15:35:39+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:40 katarynka go-librespot[13839]: time="2026-03-24T15:35:40+01:00" level=debug msg="completed challenge" Mar 24 15:35:40 katarynka sudo[13847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 15:35:40 katarynka sudo[13847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:40 katarynka volumio[13483]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 15:35:40 katarynka sudo[13847]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:40 katarynka volumio[13483]: info: Initializing connection to go-librespot Websocket Mar 24 15:35:40 katarynka volumio[13483]: error: Cannot start Volumio Streaming Daemon Mar 24 15:35:40 katarynka volumio[13483]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 15:35:40 katarynka volumio[13483]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 15:35:40 katarynka go-librespot[13839]: time="2026-03-24T15:35:40+01:00" level=debug msg="new websocket client" Mar 24 15:35:40 katarynka volumio[13483]: info: Connection to go-librespot Websocket established Mar 24 15:35:40 katarynka go-librespot[13839]: time="2026-03-24T15:35:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:40 katarynka volumio[13483]: info: Connection to go-librespot Websocket closed Mar 24 15:35:40 katarynka volumio[13483]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 15:35:41 katarynka volumio[13483]: info: MyVolumio token set successfully Mar 24 15:35:41 katarynka volumio[13483]: info: MYVOLUMIO: Adding device Mar 24 15:35:41 katarynka volumio[13483]: info: MYVOLUMIO: Evaluating Server Mar 24 15:35:41 katarynka volumio[13483]: info: MyVolumio status changed Mar 24 15:35:41 katarynka volumio[13483]: info: Streaming services startup Mar 24 15:35:41 katarynka volumio[13483]: info: Starting Streaming Daemon Mar 24 15:35:41 katarynka volumio[13483]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 15:35:41 katarynka volumio[13483]: info: Removing audio output: Mar 24 15:35:41 katarynka volumio[13483]: info: Stoppping Tunnel 1 Mar 24 15:35:41 katarynka sudo[13888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 15:35:41 katarynka sudo[13888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:42 katarynka sudo[13890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 15:35:42 katarynka sudo[13890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 15:35:42 katarynka sudo[13888]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:42 katarynka volumio[13483]: error: Cannot start Volumio Streaming Daemon Mar 24 15:35:42 katarynka volumio[13483]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 15:35:42 katarynka volumio[13483]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 15:35:42 katarynka sudo[13890]: pam_unix(sudo:session): session closed for user root Mar 24 15:35:42 katarynka volumio[13483]: info: Remote SSH Stopped Mar 24 15:35:42 katarynka volumio[13483]: info: Setting Geolocation for MyVolumio to eu6 Mar 24 15:35:42 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:42 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:42 katarynka volumio[13483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 15:35:42 katarynka volumio[13483]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 24 15:35:43 katarynka volumio[13483]: info: Getting Spotify volume Mar 24 15:35:43 katarynka volumio[13483]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 15:35:43 katarynka volumio[13483]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 15:35:43 katarynka volumio[13483]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 15:35:43 katarynka volumio[13483]: errno: -111, Mar 24 15:35:43 katarynka volumio[13483]: code: 'ECONNREFUSED', Mar 24 15:35:43 katarynka volumio[13483]: syscall: 'connect', Mar 24 15:35:43 katarynka volumio[13483]: address: '127.0.0.1', Mar 24 15:35:43 katarynka volumio[13483]: port: 9879, Mar 24 15:35:43 katarynka volumio[13483]: response: undefined Mar 24 15:35:43 katarynka volumio[13483]: } Mar 24 15:35:43 katarynka volumio[13483]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 15:35:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 24 15:35:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 15:35:43 katarynka go-librespot[13897]: go-librespot daemon starting... Mar 24 15:35:43 katarynka go-librespot[13906]: time="2026-03-24T15:35:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 15:35:43 katarynka go-librespot[13906]: time="2026-03-24T15:35:43+01:00" level=debug msg="app state loaded" Mar 24 15:35:43 katarynka go-librespot[13906]: time="2026-03-24T15:35:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 15:35:43 katarynka go-librespot[13906]: time="2026-03-24T15:35:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 15:35:43 katarynka go-librespot[13906]: time="2026-03-24T15:35:43+01: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]" Mar 24 15:35:43 katarynka go-librespot[13906]: time="2026-03-24T15:35:43+01: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]" Mar 24 15:35:43 katarynka go-librespot[13906]: time="2026-03-24T15:35:43+01:00" level=info msg="zeroconf server listening on port 46331" Mar 24 15:35:44 katarynka go-librespot[13906]: time="2026-03-24T15:35:44+01:00" level=debug msg="obtained new client token: AADu4ztA19wyOnigfjjeDvJLCnYyf+pr7oEGQK+w4qTbBJpyrT4hcXMmuaMN5Wy8j/M9DCmVaSnhRqWNCOLUdmHYYYaexAHCC7YON+4CL9Vrz6s9ZmS9fQmm8OkGfjmikcCLhAg9My4yQb0BttWv3Inh4jawSOGHj33Hx3Ix6BtEF1GyoMQ6NQW2qw4h5vPZh9x9s5RV65ZiMU0PNCgXg3QfZTeZqVqp3wQRlaAMAsaF00vJbksAWGuT" Mar 24 15:35:44 katarynka go-librespot[13906]: time="2026-03-24T15:35:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 15:35:44 katarynka go-librespot[13906]: time="2026-03-24T15:35:44+01:00" level=debug msg="completed keyexchange" Mar 24 15:35:44 katarynka go-librespot[13906]: time="2026-03-24T15:35:44+01:00" level=debug msg="completed challenge" Mar 24 15:35:44 katarynka go-librespot[13906]: time="2026-03-24T15:35:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 15:35:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 15:35:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 15:35:44 katarynka sudo[13917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 15:34' Mar 24 15:35:44 katarynka sudo[13917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"