Mar 25 23:26:00 katarynka volumio[20356]: info: Volumio Calling Home Mar 25 23:26:01 katarynka kernel: usb 1-1.3: reset full-speed USB device number 6 using dwc_otg Mar 25 23:26:01 katarynka sudo[20591]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 23:26:01 katarynka sudo[20591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:01 katarynka sudo[20591]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:01 katarynka volumio[20356]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 23:26:01 katarynka volumio[20356]: info: Discovery: Found device katarynka Mar 25 23:26:01 katarynka volumio[20356]: info: CoreCommandRouter::volumioGetState Mar 25 23:26:01 katarynka volumio[20356]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:01 katarynka sudo[20589]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 23:26:01 katarynka sudo[20589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:01 katarynka volumio[20356]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 23:26:01 katarynka volumio[20356]: info: Discovery: Found device katarynka Mar 25 23:26:01 katarynka sudo[20589]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:01 katarynka volumio[20356]: info: CoreCommandRouter::volumioGetState Mar 25 23:26:01 katarynka volumio[20356]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:01 katarynka volumio[20356]: info: MPD Permissions set Mar 25 23:26:01 katarynka volumio[20356]: info: MPD Permissions set Mar 25 23:26:01 katarynka volumio[20356]: info: VolumeController:: Volume=96 Mute =false Mar 25 23:26:01 katarynka volumio[20356]: info: CoreStateMachine::pushState Mar 25 23:26:01 katarynka volumio[20356]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:01 katarynka volumio[20356]: info: CoreCommandRouter::volumioPushState Mar 25 23:26:01 katarynka volumio-remote-updater[686]: [2026-03-25 23:26:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774477559 101 Mar 25 23:26:01 katarynka volumio[20356]: 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 25 23:26:01 katarynka volumio[20356]: info: Volumio called home Mar 25 23:26:01 katarynka volumio[20356]: info: Spotify config file written Mar 25 23:26:02 katarynka sudo[20597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 23:26:02 katarynka sudo[20597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:02 katarynka volumio[20483]: Starting albumart workers Mar 25 23:26:02 katarynka volumio[20356]: 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 25 23:26:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:02 katarynka go-librespot[20599]: go-librespot daemon starting... Mar 25 23:26:02 katarynka sudo[20597]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka go-librespot[20602]: time="2026-03-25T23:26:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:02 katarynka go-librespot[20602]: time="2026-03-25T23:26:02+01:00" level=debug msg="app state loaded" Mar 25 23:26:02 katarynka go-librespot[20602]: time="2026-03-25T23:26:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20482]: Starting albumart workers Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:02 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:02 katarynka volumio[20481]: Starting albumart workers Mar 25 23:26:02 katarynka volumio[20356]: info: No need to fix Spotify hosts Mar 25 23:26:02 katarynka go-librespot[20602]: time="2026-03-25T23:26:02+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 25 23:26:02 katarynka go-librespot[20602]: time="2026-03-25T23:26:02+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 25 23:26:02 katarynka go-librespot[20602]: time="2026-03-25T23:26:02+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 25 23:26:02 katarynka go-librespot[20602]: time="2026-03-25T23:26:02+01:00" level=info msg="zeroconf server listening on port 44397" Mar 25 23:26:03 katarynka go-librespot[20602]: time="2026-03-25T23:26:03+01:00" level=debug msg="obtained new client token: AAACuU8R5JlODgdF42j3TvAdkNq/4hZSA18qThCDMlPlT4ea6Ic7VktAIMqeGVbRWUloFqM1KMmeZYUk7AAN1IoQcZhrQ4/UbKvsb+afhpi9nQHIuJILK/FU2qu/6tZ4tAPHvXrKomtrJ0l13N7w7pSChcZe1jCjrZd5/qL/dC+6W3C8drvtS5bCRBUuWW8QV7OUBZteSS7rL0kVcjbwuv/iB8tlq+t5SNQFwzMruyXMiiUdvna0X+ky" Mar 25 23:26:03 katarynka go-librespot[20602]: time="2026-03-25T23:26:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:03 katarynka go-librespot[20602]: time="2026-03-25T23:26:03+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:03 katarynka go-librespot[20602]: time="2026-03-25T23:26:03+01:00" level=debug msg="completed challenge" Mar 25 23:26:03 katarynka go-librespot[20602]: time="2026-03-25T23:26:03+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 25 23:26:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:03 katarynka volumio[20356]: info: Mar 25 23:26:03 katarynka volumio[20356]: ---------------------------- USB Audio Device Detached Mar 25 23:26:03 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Mar 25 23:26:03 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 25 23:26:03 katarynka kernel: usb 1-1.3: reset full-speed USB device number 6 using dwc_otg Mar 25 23:26:03 katarynka volumio[20356]: info: Starting Shairport Sync Mar 25 23:26:03 katarynka volumio[20356]: info: Starting Shairport Sync Mar 25 23:26:03 katarynka volumio[20356]: info: Starting Shairport Sync Mar 25 23:26:03 katarynka sudo[20623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:26:03 katarynka sudo[20623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:04 katarynka sudo[20625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:26:04 katarynka sudo[20625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:04 katarynka sudo[20630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 23:26:04 katarynka sudo[20630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:04 katarynka sudo[20628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:26:04 katarynka volumio[20356]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 23:26:04 katarynka sudo[20628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:04 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 23:26:04 katarynka sudo[20630]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:04 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 23:26:04 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:26:04 katarynka systemd[1]: shairport-sync.service: Consumed 2.332s CPU time. Mar 25 23:26:04 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:26:04 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 23:26:04 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 23:26:04 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 23:26:04 katarynka sudo[20623]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:04 katarynka sudo[20625]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:04 katarynka sudo[20628]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:04 katarynka volumio[20356]: info: Upmpdcli Daemon Started Mar 25 23:26:04 katarynka volumio[20356]: info: Mar 25 23:26:04 katarynka volumio[20356]: ---------------------------- USB Audio Device Attached Mar 25 23:26:04 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Mar 25 23:26:04 katarynka volumio[20356]: info: Shairport-Sync Started Mar 25 23:26:04 katarynka volumio[20356]: Error adding Membership: Error: addMembership EINVAL Mar 25 23:26:04 katarynka volumio[20356]: info: Shairport-Sync Started Mar 25 23:26:04 katarynka volumio[20356]: info: Shairport-Sync Started Mar 25 23:26:04 katarynka volumio[20356]: info: CoreCommandRouter::volumioGetState Mar 25 23:26:04 katarynka volumio[20356]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:04 katarynka volumio[20356]: info: Mar 25 23:26:04 katarynka volumio[20356]: ---------------------------- USB Audio Device Detached Mar 25 23:26:04 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Mar 25 23:26:04 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 25 23:26:05 katarynka volumio[20356]: info: Mar 25 23:26:05 katarynka volumio[20356]: ---------------------------- USB Audio Device Attached Mar 25 23:26:05 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Mar 25 23:26:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Mar 25 23:26:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:06 katarynka go-librespot[20673]: go-librespot daemon starting... Mar 25 23:26:06 katarynka systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 25 23:26:06 katarynka go-librespot[20674]: time="2026-03-25T23:26:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:06 katarynka go-librespot[20674]: time="2026-03-25T23:26:06+01:00" level=debug msg="app state loaded" Mar 25 23:26:06 katarynka go-librespot[20674]: time="2026-03-25T23:26:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:06 katarynka volumio[20356]: info: go-librespot daemon successfully initialized Mar 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+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 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+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 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+01:00" level=info msg="zeroconf server listening on port 43203" Mar 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+01:00" level=debug msg="obtained new client token: AAC2x82mQ+NZOGcy2HFv1jPSdSiVqVd95FJa3J4Iw1VNcqiI5CnCT6s71VY/CRH3xElMpqT3sFDNM/F0h6aZPTEHMP3fSS4jW1nXpNkRrjYjLXPPiphNf6LzIFCKO24O2In/2eX6pbrlKpmafWe3MoJJgf4wyGguGlfoOg97pz/KPv8I/yJWXUEpJQu5K8fkofPn4/vLl4nph8W8rKxPgXvytiCU5jZ17ma/c2Lp9nNnSXuCOYzKwnOv" Mar 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+01:00" level=debug msg="completed challenge" Mar 25 23:26:07 katarynka go-librespot[20674]: time="2026-03-25T23:26:07+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 25 23:26:07 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:07 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:07 katarynka mpd[20566]: 2026-03-25T23:26:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 23:26:07 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 23:26:07 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 23:26:07 katarynka sudo[20518]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:07 katarynka sudo[20528]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:07 katarynka volumio[20356]: info: Completed starting Core Plugins Mar 25 23:26:07 katarynka volumio[20356]: info: ------------------------------------------- Mar 25 23:26:07 katarynka volumio[20356]: info: ----- MyVolumio plugins startup ---- Mar 25 23:26:07 katarynka volumio[20356]: info: ------------------------------------------- Mar 25 23:26:07 katarynka volumio[20356]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 23:26:07 katarynka volumio[20356]: error: MPD error: The expression evaluated to a falsy value: Mar 25 23:26:07 katarynka volumio[20356]: assert.ok(self.idling) Mar 25 23:26:07 katarynka volumio[20356]: error: The expression evaluated to a falsy value: Mar 25 23:26:07 katarynka volumio[20356]: assert.ok(self.idling) Mar 25 23:26:07 katarynka volumio[20356]: info: MPD running with PID20566 Mar 25 23:26:07 katarynka volumio[20356]: ,establishing connection Mar 25 23:26:07 katarynka volumio[20356]: error: updateQueue error: null Mar 25 23:26:07 katarynka volumio[20356]: error: updateQueue error: null Mar 25 23:26:08 katarynka systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 25 23:26:08 katarynka systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 25 23:26:08 katarynka systemd[1]: setdatetime-helper.service: Consumed 1.935s CPU time. Mar 25 23:26:09 katarynka volumio[20356]: info: Initializing connection to go-librespot Websocket Mar 25 23:26:09 katarynka volumio[20356]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 23:26:10 katarynka sudo[20729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 23:26:10 katarynka sudo[20729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:10 katarynka sudo[20731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 23:26:10 katarynka sudo[20731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:10 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Mar 25 23:26:10 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:10 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:10 katarynka go-librespot[20734]: go-librespot daemon starting... Mar 25 23:26:10 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 23:26:10 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 23:26:10 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 23:26:10 katarynka go-librespot[20735]: time="2026-03-25T23:26:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:10 katarynka go-librespot[20735]: time="2026-03-25T23:26:10+01:00" level=debug msg="app state loaded" Mar 25 23:26:10 katarynka go-librespot[20735]: time="2026-03-25T23:26:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:10 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 23:26:10 katarynka sudo[20729]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:10 katarynka sudo[20731]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:10 katarynka mpd_monitor.sh[20741]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 23:26:10 katarynka volumio[20356]: info: Successfully started MPD Monitor Mar 25 23:26:10 katarynka volumio[20356]: info: Successfully started MPD Monitor Mar 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26: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-gae2.spotify.com:80]" Mar 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+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 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+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 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+01:00" level=info msg="zeroconf server listening on port 33475" Mar 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+01:00" level=debug msg="obtained new client token: AAAxIdzYzjeG0Z7c5nKxulFimf5cNAXVSvndPyleNbzMhfTYQQc0a0IuRS//Gs49u13zU+pVqc/7K7YhIxf14Vs/+X6PdqFVfj7LrRiMcnaE5IyHOzIE7zngxmh0wmIkUmKOa+r7oeQ7HTX4/dsA2kc9KAm+jp/fJWSl7rPcCuoUFF8BKGM7PVBlWFg0ZqNszFXkQHfGvdsshUyvpbKVO5Gz/zYuQjeO7xHtNyYuoD5FFpHBbcBcCeBgQs0=" Mar 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+01:00" level=debug msg="completed challenge" Mar 25 23:26:11 katarynka go-librespot[20735]: time="2026-03-25T23:26:11+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 25 23:26:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:12 katarynka volumio[20356]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 23:26:12 katarynka volumio[20356]: info: Initializing connection to go-librespot Websocket Mar 25 23:26:12 katarynka volumio[20356]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 23:26:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Mar 25 23:26:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:14 katarynka go-librespot[20746]: go-librespot daemon starting... Mar 25 23:26:14 katarynka go-librespot[20747]: time="2026-03-25T23:26:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:14 katarynka go-librespot[20747]: time="2026-03-25T23:26:14+01:00" level=debug msg="app state loaded" Mar 25 23:26:14 katarynka go-librespot[20747]: time="2026-03-25T23:26:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+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 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+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 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+01:00" level=info msg="zeroconf server listening on port 45579" Mar 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+01:00" level=debug msg="obtained new client token: AAC/S4dZBr32pMt7Wb3DNOwDh4MnneiVSXRA9Ajb9TQdkUHhHg9KBcvfxNhnB493mY0No4SwDmqNgF9yvRW54JO4iwt+PB0Le75NWhvBF113zKp+RPcbqYdZV4I/VK4wtRH0Q7nBzW8wgbFg+s7dk5L6PO3N1s2Dgk4gUpbwrDfNCNe3jhFd63OcIUCac+CmSEiLpGkzl86AZ5qnxrEVakJz73tKiEqMNcqmt0d+teTlF845VRIcs+YT17U=" Mar 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:15 katarynka volumio[20356]: info: Initializing connection to go-librespot Websocket Mar 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+01:00" level=debug msg="new websocket client" Mar 25 23:26:15 katarynka volumio[20356]: info: Connection to go-librespot Websocket established Mar 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:15 katarynka go-librespot[20747]: time="2026-03-25T23:26:15+01:00" level=debug msg="completed challenge" Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 23:26:16 katarynka volumio[20356]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 23:26:16 katarynka volumio[20356]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 23:26:16 katarynka volumio[20356]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 23:26:16 katarynka volumio[20356]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 23:26:16 katarynka volumio[20356]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 23:26:16 katarynka volumio[20356]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 23:26:16 katarynka volumio[20356]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 23:26:16 katarynka volumio[20356]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 23:26:16 katarynka go-librespot[20747]: time="2026-03-25T23:26: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 25 23:26:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:17 katarynka volumio[20356]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 23:26:17 katarynka volumio[20356]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 23:26:17 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:17 katarynka volumio[20356]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:17 katarynka volumio[20356]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 23:26:18 katarynka volumio[20356]: info: MyVolumio login type: Token Mar 25 23:26:18 katarynka volumio[20356]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 23:26:18 katarynka volumio[20356]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 23:26:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Mar 25 23:26:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:19 katarynka go-librespot[20756]: go-librespot daemon starting... Mar 25 23:26:19 katarynka go-librespot[20757]: time="2026-03-25T23:26:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:19 katarynka go-librespot[20757]: time="2026-03-25T23:26:19+01:00" level=debug msg="app state loaded" Mar 25 23:26:19 katarynka go-librespot[20757]: time="2026-03-25T23:26:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:19 katarynka volumio[20356]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 23:26:19 katarynka volumio[20356]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 23:26:19 katarynka volumio[20356]: info: Streaming services startup Mar 25 23:26:19 katarynka volumio[20356]: info: Starting Streaming Daemon Mar 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:19+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 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:19+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 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:20+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 25 23:26:20 katarynka sudo[20766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 23:26:20 katarynka sudo[20766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:20 katarynka volumio[20356]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:20+01:00" level=info msg="zeroconf server listening on port 46405" Mar 25 23:26:20 katarynka sudo[20766]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:20+01:00" level=debug msg="obtained new client token: AAAcPHUMcKVO+iK24fmP0G0toLUMT8fpveKsH9z0AKe4GM4Ncycd7tCicXMw944nSpZwRXbWDuSpOhGndG1y4lx8EK9i6NaCVdhtmoxrIaLxrYYlIM+L/wtNEu/6vMBtiCuAlESFSrla0XfioYFlnrmYg0kfl+ZVRoNmXNzjA/wdiPcir7NKx00365myglB6zG75f4Zq4siQW1MXJELiMLAV3/yes1td7Ztt5uO47po9QXCE4ddviuFR" Mar 25 23:26:20 katarynka volumio[20356]: info: Getting Spotify volume Mar 25 23:26:20 katarynka volumio[20356]: info: Connection to go-librespot Websocket closed Mar 25 23:26:20 katarynka volumio[20356]: error: Cannot start Volumio Streaming Daemon Mar 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:20 katarynka volumio[20356]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 23:26:20 katarynka volumio[20356]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 23:26:20 katarynka volumio[20356]: 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 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:20+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26:20+01:00" level=debug msg="completed challenge" Mar 25 23:26:20 katarynka go-librespot[20757]: time="2026-03-25T23:26: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 25 23:26:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:20 katarynka volumio[20356]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 23:26:20 katarynka volumio[20356]: Error: socket hang up Mar 25 23:26:20 katarynka volumio[20356]: at connResetException (node:internal/errors:720:14) Mar 25 23:26:20 katarynka volumio[20356]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 23:26:20 katarynka volumio[20356]: at Socket.emit (node:events:526:35) Mar 25 23:26:20 katarynka volumio[20356]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 23:26:20 katarynka volumio[20356]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 23:26:20 katarynka volumio[20356]: code: 'ECONNRESET', Mar 25 23:26:20 katarynka volumio[20356]: response: undefined Mar 25 23:26:20 katarynka volumio[20356]: } Mar 25 23:26:20 katarynka volumio[20356]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 23:26:21 katarynka sudo[20801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 23:25' Mar 25 23:26:21 katarynka sudo[20801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:22 katarynka sudo[20801]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:22 katarynka volumio-remote-updater[686]: [2026-03-25 23:26:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 23:26:22 katarynka volumio-remote-updater[686]: [2026-03-25 23:26:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 23:26:22 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:22 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 23:26:22 katarynka systemd[1]: volumio.service: Consumed 49.533s CPU time. Mar 25 23:26:22 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 23:26:22 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 23:26:22 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 401. Mar 25 23:26:22 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 23:26:22 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 23:26:22 katarynka systemd[1]: volumio.service: Consumed 49.533s CPU time. Mar 25 23:26:23 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 23:26:23 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 23:26:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Mar 25 23:26:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:23 katarynka go-librespot[20831]: go-librespot daemon starting... Mar 25 23:26:23 katarynka go-librespot[20833]: time="2026-03-25T23:26:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:23 katarynka go-librespot[20833]: time="2026-03-25T23:26:23+01:00" level=debug msg="app state loaded" Mar 25 23:26:23 katarynka go-librespot[20833]: time="2026-03-25T23:26:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+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 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+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 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+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 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+01:00" level=info msg="zeroconf server listening on port 44013" Mar 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+01:00" level=debug msg="obtained new client token: AAAVn2RcBzAACeXE+ec5Znzy66j8tqnXqo03skyL6RT1DTHpsjfDQyiVDQsQc4h+en9G50LM6IaTjmQfdfD1HIN1nc3bwS8F3iDLMvJT4ppdmeJoavf5HygTnwxPtACAOfSzqA3aJoihkiuPVvWp66WcS3U/mTgHUUjVnCW7+fk7W/7bcaen8Xe4DpRV67xP2fCWbz21dNzSgMQPf9FTGR/s2LzfFdBwYXEZthC3rjZPQRd+Lz0iPDTA2EE=" Mar 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+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 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+01:00" level=debug msg="completed challenge" Mar 25 23:26:24 katarynka go-librespot[20833]: time="2026-03-25T23:26:24+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 25 23:26:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:26 katarynka volumio[20816]: info: ------------------------------------------- Mar 25 23:26:26 katarynka volumio[20816]: info: ----- Volumio3 ---- Mar 25 23:26:26 katarynka volumio[20816]: info: ------------------------------------------- Mar 25 23:26:26 katarynka volumio[20816]: info: ----- System startup ---- Mar 25 23:26:26 katarynka volumio[20816]: info: ------------------------------------------- Mar 25 23:26:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Mar 25 23:26:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:27 katarynka go-librespot[20847]: go-librespot daemon starting... Mar 25 23:26:27 katarynka go-librespot[20848]: time="2026-03-25T23:26:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:27 katarynka go-librespot[20848]: time="2026-03-25T23:26:27+01:00" level=debug msg="app state loaded" Mar 25 23:26:27 katarynka go-librespot[20848]: time="2026-03-25T23:26:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:27 katarynka volumio-remote-updater[686]: [2026-03-25 23:26:27] [connect] Successful connection Mar 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+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 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+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 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+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 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+01:00" level=info msg="zeroconf server listening on port 40241" Mar 25 23:26:28 katarynka volumio[20816]: info: MYVOLUMIO Environment detected Mar 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+01:00" level=debug msg="obtained new client token: AADibOSW3GoToKW5Dbg5Ew3kiBhkFZ4UQ4E5mTjy8sAaRfq1ejoBi7jODcKd5LNUcVP669vvz8xu39JCFzgcqoxXjZYIO04Lr8XEArro0g2w25OiEhMCZXYUkZZks6PxeNuHDObyEAm5pyS6nzk2do1jjJtdJmu8f9rNRHNKjV8whOTgKwnereVhgN7sHhSK5tIOcTE53Aa4FRI5+Yvuno8rGYM92FuhraKCwGSsSpoOJSbRqKhy4+Fk4TY=" Mar 25 23:26:28 katarynka volumio[20816]: info: Plugin folders cleanup Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning into folder /volumio/app/plugins/ Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning category audio_interface Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning category miscellanea Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning category music_service Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning category plugins.json Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning category system_controller Mar 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning category user_interface Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning into folder /data/plugins/ Mar 25 23:26:28 katarynka volumio[20816]: info: Scanning category music_service Mar 25 23:26:28 katarynka volumio[20816]: info: Plugin folders cleanup completed Mar 25 23:26:28 katarynka volumio[20816]: info: ------------------------------------------- Mar 25 23:26:28 katarynka volumio[20816]: info: ----- Core plugins startup ---- Mar 25 23:26:28 katarynka volumio[20816]: info: ------------------------------------------- Mar 25 23:26:28 katarynka volumio[20816]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 23:26:28 katarynka volumio[20816]: info: Adding plugin upnp to MyMusic Plugins Mar 25 23:26:28 katarynka volumio[20816]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 23:26:28 katarynka volumio[20816]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 23:26:28 katarynka volumio[20816]: info: Loading plugins from folder /data/plugins/ Mar 25 23:26:28 katarynka volumio[20816]: info: Loading plugin "system"... Mar 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+01:00" level=debug msg="completed challenge" Mar 25 23:26:28 katarynka go-librespot[20848]: time="2026-03-25T23:26:28+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 25 23:26:28 katarynka volumio[20816]: info: Loading plugin "appearance"... Mar 25 23:26:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:30 katarynka volumio[20816]: info: Loading plugin "network"... Mar 25 23:26:30 katarynka volumio[20816]: info: Refreshing Cached IP Addresses Mar 25 23:26:30 katarynka sudo[20862]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 23:26:30 katarynka sudo[20862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:30 katarynka sudo[20864]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 23:26:30 katarynka sudo[20864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:30 katarynka volumio[20816]: info: Loading plugin "services"... Mar 25 23:26:30 katarynka volumio[20816]: info: Loading plugin "alsa_controller"... Mar 25 23:26:30 katarynka sudo[20862]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:30 katarynka sudo[20864]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:30 katarynka sudo[20872]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 23:26:30 katarynka sudo[20872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:30 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 23:26:30 katarynka volumio[20816]: info: Loading plugin "wizard"... Mar 25 23:26:30 katarynka volumio[20816]: info: Loading plugin "networkfs"... Mar 25 23:26:30 katarynka volumio[20816]: info: Starting Udev Watcher for removable devices Mar 25 23:26:30 katarynka volumio[20816]: info: Ignoring mount for partition: boot Mar 25 23:26:30 katarynka volumio[20816]: info: Ignoring mount for partition: volumio Mar 25 23:26:30 katarynka volumio[20816]: info: Ignoring mount for partition: volumio_data Mar 25 23:26:30 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 23:26:30 katarynka volumio[20816]: info: Loading plugin "volumio_command_line_client"... Mar 25 23:26:31 katarynka volumio[20816]: info: Loading plugin "upnp"... Mar 25 23:26:31 katarynka volumio[20816]: info: [1774477591017] Starting Upmpd Daemon Mar 25 23:26:31 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 23:26:31 katarynka volumio[20816]: info: Loading plugin "my_music"... Mar 25 23:26:31 katarynka volumio[20816]: info: Loading plugin "mpd"... Mar 25 23:26:31 katarynka sudo[20872]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Mar 25 23:26:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:31 katarynka volumio[20816]: info: Loading plugin "upnp_browser"... Mar 25 23:26:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:31 katarynka go-librespot[20898]: go-librespot daemon starting... Mar 25 23:26:31 katarynka go-librespot[20900]: time="2026-03-25T23:26:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:31 katarynka go-librespot[20900]: time="2026-03-25T23:26:31+01:00" level=debug msg="app state loaded" Mar 25 23:26:31 katarynka go-librespot[20900]: time="2026-03-25T23:26:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+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 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+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 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+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 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+01:00" level=info msg="zeroconf server listening on port 44659" Mar 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+01:00" level=debug msg="obtained new client token: AAC9nHMLswbcuFaIvNIj++rbL9NyMv71DEOFYxlkPPAzGMk0v1r0mS1lg9Z1O4W89nZPDgjL2jX7C4vPE6W975zpnxk7vMLq5txyeKo4hnmaAmRVhC8b/GtREIe94zrp0BLFiWImx30z2n54XOoDdxVNX6w5bJvEmKQKyPXdcZc+lz2/0FxyiYy825koBHMduGnFOaO6CksIq6ZL3an0gNm+ehvL2uMuD0WfhB2HC1LCYXtQEPaFdkGqLQY=" Mar 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+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 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+01:00" level=debug msg="completed challenge" Mar 25 23:26:32 katarynka go-librespot[20900]: time="2026-03-25T23:26:32+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 25 23:26:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:34 katarynka volumio[20816]: info: Starting UPNP Browser Mar 25 23:26:34 katarynka volumio[20816]: info: Loading plugin "alarm-clock"... Mar 25 23:26:35 katarynka volumio[20816]: info: Loading plugin "airplay_emulation"... Mar 25 23:26:35 katarynka volumio[20816]: info: Starting Shairport Sync Mar 25 23:26:35 katarynka volumio[20816]: info: Loading plugin "last_100"... Mar 25 23:26:35 katarynka volumio[20816]: info: Loading plugin "webradio"... Mar 25 23:26:35 katarynka volumio[20816]: info: Loading plugin "i2s_dacs"... Mar 25 23:26:35 katarynka volumio[20816]: info: Loading plugin "volumiodiscovery"... Mar 25 23:26:35 katarynka volumio[20816]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 23:26:35 katarynka volumio[20816]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:26:35 katarynka volumio[20816]: *** WARNING *** For more information see Mar 25 23:26:35 katarynka volumio[20816]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 23:26:35 katarynka volumio[20816]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:26:35 katarynka volumio[20816]: *** WARNING *** For more information see Mar 25 23:26:35 katarynka node[20816]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 23:26:35 katarynka node[20816]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:26:35 katarynka node[20816]: *** WARNING *** For more information see Mar 25 23:26:35 katarynka node[20816]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 23:26:35 katarynka node[20816]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:26:35 katarynka node[20816]: *** WARNING *** For more information see Mar 25 23:26:35 katarynka volumio[20816]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 23:26:35 katarynka volumio[20816]: info: Discovery: Started advertising with name: katarynka Mar 25 23:26:35 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 23:26:35 katarynka volumio[20816]: info: Loading plugin "spop"... Mar 25 23:26:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Mar 25 23:26:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:36 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:36 katarynka go-librespot[20910]: go-librespot daemon starting... Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=debug msg="app state loaded" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+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 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+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 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+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 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=info msg="zeroconf server listening on port 46583" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=debug msg="obtained new client token: AACymlav2Wp4MAB7qndqU2dMAOML/CY7GdC/94KElEPS2xMbAzcpuH4/66ZCtZFqjzUvUB4sz51KT04yMPsQi2ebXrAF0dGgBRpvwdKs11AJL0Rsn3m0sWsgg976L2GU/iv2rFyFdLOcqqtSJtNvMMkAAIEJpHLsihYc40uw2QuZLh5ddYKMUHZQsr1BpvgYfwNv3y2GWIJ2DiGFVa3GIgN56NgVp7lYo9hzZg4aJGtu9DRSIHwsSfuDw/o=" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26:36+01:00" level=debug msg="completed challenge" Mar 25 23:26:36 katarynka go-librespot[20911]: time="2026-03-25T23:26: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 25 23:26:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:37 katarynka volumio[20816]: info: Loading plugin "outputs"... Mar 25 23:26:37 katarynka volumio[20816]: info: Loading plugin "albumart"... Mar 25 23:26:37 katarynka volumio[20816]: info: Plugin example_plugin is not enabled Mar 25 23:26:37 katarynka volumio[20816]: info: Loading plugin "inputs"... Mar 25 23:26:37 katarynka volumio[20816]: info: Loading plugin "updater_comm"... Mar 25 23:26:37 katarynka volumio[20816]: info: Plugin mpdemulation is not enabled Mar 25 23:26:37 katarynka volumio[20816]: info: Loading plugin "rest_api"... Mar 25 23:26:37 katarynka volumio[20816]: info: Loading plugin "websocket"... Mar 25 23:26:37 katarynka volumio[20816]: info: Starting Socket.io Server version 1.7.4 Mar 25 23:26:37 katarynka volumio[20816]: info: Loading i18n strings for locale pl Mar 25 23:26:37 katarynka volumio[20816]: Updating browse sources language Mar 25 23:26:37 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::initPlayerControls Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: Express server listening on port 3000 Mar 25 23:26:38 katarynka volumio[20816]: [Metrics] WebUI: 12s 472.65ms Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::resetVolumioState Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::getcurrentVolume Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 23:26:38 katarynka volumio[20816]: info: Cannot read play queue from file Mar 25 23:26:38 katarynka volumio[20816]: info: Volumio Network Manager: Network status updated: 2 Mar 25 23:26:38 katarynka volumio[20918]: Forking 3 albumart workers Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:38 katarynka volumio[20816]: info: VolumeController:: Volume=96 Mute =false Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::pushState Mar 25 23:26:38 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::volumioPushState Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::updateTrackBlock Mar 25 23:26:38 katarynka volumio[20816]: info: CorePlayQueue::getTrackBlock Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::setRepeat null single undefined Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::pushState Mar 25 23:26:38 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::volumioPushState Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::setRandom null Mar 25 23:26:38 katarynka volumio[20816]: info: CoreStateMachine::pushState Mar 25 23:26:38 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:38 katarynka volumio[20816]: info: CoreCommandRouter::volumioPushState Mar 25 23:26:38 katarynka volumio[20816]: info: Setting Device type: Raspberry PI Mar 25 23:26:38 katarynka volumio[20816]: info: Completed loading Core Plugins Mar 25 23:26:38 katarynka volumio[20816]: info: Preparing to generate the ALSA configuration file Mar 25 23:26:39 katarynka volumio[20816]: info: Asound.conf file unchanged, so no further update is needed Mar 25 23:26:39 katarynka volumio[20816]: info: Output device has changed, restarting MPD Mar 25 23:26:39 katarynka volumio[20816]: info: Output device has changed, restarting Shairport Sync Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:39 katarynka sudo[20972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 23:26:39 katarynka volumio[20816]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 23:26:39 katarynka sudo[20972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:39 katarynka sudo[20974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 23:26:39 katarynka sudo[20974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:39 katarynka volumio[20816]: info: ___________ START PLUGINS ___________ Mar 25 23:26:39 katarynka sudo[20972]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:39 katarynka volumio[20816]: info: ControllerMpd::onStart: Initializing MPD Mar 25 23:26:39 katarynka volumio[20816]: info: Creating MPD Configuration file Mar 25 23:26:39 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 23:26:39 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 23:26:39 katarynka volumio[20816]: info: [1774477599397] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:26:39 katarynka sudo[20982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 23:26:39 katarynka sudo[20982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:39 katarynka sudo[20984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 23:26:39 katarynka sudo[20984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:39 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 23:26:39 katarynka sudo[20982]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:39 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 23:26:39 katarynka systemd[1]: mpd.service: Consumed 7.937s CPU time. Mar 25 23:26:39 katarynka volumio[20816]: info: UPNP Browser: Client initialized successfully Mar 25 23:26:39 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 23:26:39 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 23:26:39 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 23:26:39 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:39 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 23:26:39 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 23:26:39 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 23:26:39 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 23:26:39 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 23:26:39 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 23:26:39 katarynka volumio[20816]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:39 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 23:26:39 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 23:26:39 katarynka volumio[20816]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 23:26:39 katarynka volumio[20816]: info: [1774477599823] CoreMusicLibrary::Adding element Last_100 Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 23:26:39 katarynka volumio[20816]: info: [1774477599850] CoreMusicLibrary::Adding element Webradio Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:26:39 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 23:26:39 katarynka volumio[20816]: info: Initializing BBC Radios Mar 25 23:26:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Mar 25 23:26:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:40 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:40 katarynka go-librespot[21002]: go-librespot daemon starting... Mar 25 23:26:40 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+01:00" level=debug msg="app state loaded" Mar 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:40 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:40 katarynka volumio[20816]: info: Creating Spotify config file Mar 25 23:26:40 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:40 katarynka volumio-remote-updater[686]: [2026-03-25 23:26:40] [connect] Successful connection Mar 25 23:26:40 katarynka sudo[20998]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 23:26:40 katarynka sudo[20998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 23:26:40 katarynka sudo[20998]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+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 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+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 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+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 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+01:00" level=info msg="zeroconf server listening on port 35361" Mar 25 23:26:40 katarynka go-librespot[21008]: time="2026-03-25T23:26:40+01:00" level=debug msg="obtained new client token: AADyK2C4l0nW0P+Xlhdkb7rXJFR5Znqb9L/B6paV7hF1xA9aKpqjfjpYwFfOpSpvsUjYHcTYf0IVeZju8e8S33qjddnpzk4zch/CbxZOzXieCIDMvC+KjqMIkfqLdgWGYslDrAEArN5Zv2Kg5CT8KBxQcr1b0e/07zhLBUM05iZksqHlKoC/uJEdk8jUPJN2SwuKqy/LXlTv2RF7OJYb36SX1yJ4C4CfMSiHl1mTYosj3YMkmoVOZZV8uNo=" Mar 25 23:26:41 katarynka go-librespot[21008]: time="2026-03-25T23:26:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:41 katarynka go-librespot[21008]: time="2026-03-25T23:26:41+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:41 katarynka go-librespot[21008]: time="2026-03-25T23:26:41+01:00" level=debug msg="completed challenge" Mar 25 23:26:41 katarynka go-librespot[21008]: time="2026-03-25T23:26:41+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 25 23:26:41 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:41 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:41 katarynka volumio[20816]: info: Volumio Calling Home Mar 25 23:26:42 katarynka volumio[20816]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 23:26:42 katarynka volumio[20816]: info: Discovery: Found device katarynka Mar 25 23:26:42 katarynka volumio[20816]: info: CoreCommandRouter::volumioGetState Mar 25 23:26:42 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:42 katarynka sudo[21043]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 23:26:42 katarynka sudo[21041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 23:26:42 katarynka sudo[21043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:42 katarynka sudo[21041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:42 katarynka sudo[21043]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:42 katarynka sudo[21041]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:42 katarynka volumio[20816]: info: MPD Permissions set Mar 25 23:26:42 katarynka volumio[20816]: info: MPD Permissions set Mar 25 23:26:42 katarynka volumio[20816]: info: VolumeController:: Volume=96 Mute =false Mar 25 23:26:42 katarynka volumio[20816]: info: CoreStateMachine::pushState Mar 25 23:26:42 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:42 katarynka volumio[20816]: info: CoreCommandRouter::volumioPushState Mar 25 23:26:42 katarynka volumio[20816]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 23:26:42 katarynka volumio[20816]: info: Discovery: Found device katarynka Mar 25 23:26:42 katarynka volumio[20816]: info: CoreCommandRouter::volumioGetState Mar 25 23:26:42 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:42 katarynka volumio-remote-updater[686]: [2026-03-25 23:26:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774477600 101 Mar 25 23:26:42 katarynka volumio[20932]: Starting albumart workers Mar 25 23:26:42 katarynka volumio[20816]: 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 25 23:26:42 katarynka volumio[20816]: info: Volumio called home Mar 25 23:26:42 katarynka volumio[20816]: info: Spotify config file written Mar 25 23:26:42 katarynka volumio[20934]: Starting albumart workers Mar 25 23:26:42 katarynka sudo[21047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 23:26:42 katarynka sudo[21047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:43 katarynka volumio[20816]: 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 25 23:26:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20936]: Starting albumart workers Mar 25 23:26:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:43 katarynka go-librespot[21049]: go-librespot daemon starting... Mar 25 23:26:43 katarynka sudo[21047]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka go-librespot[21055]: time="2026-03-25T23:26:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:43 katarynka go-librespot[21055]: time="2026-03-25T23:26:43+01:00" level=debug msg="app state loaded" Mar 25 23:26:43 katarynka go-librespot[21055]: time="2026-03-25T23:26:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:26:43 katarynka volumio[20816]: info: No need to fix Spotify hosts Mar 25 23:26:43 katarynka go-librespot[21055]: time="2026-03-25T23:26: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 23:26:43 katarynka go-librespot[21055]: time="2026-03-25T23:26:43+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 25 23:26:43 katarynka go-librespot[21055]: time="2026-03-25T23:26:43+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 25 23:26:43 katarynka go-librespot[21055]: time="2026-03-25T23:26:43+01:00" level=info msg="zeroconf server listening on port 45229" Mar 25 23:26:44 katarynka go-librespot[21055]: time="2026-03-25T23:26:44+01:00" level=debug msg="obtained new client token: AACucZjO8xMiqIQv5c0biTJFFMcp/MyNfQnXO8O2ZcL7Q5pR9B9gJ20/W7UaI0Q/HP7QVJFvaEHpfeGoGmqZvk+/WY3wAtRq0uP+lWRJ7pTJtXxrcsLbaHQ+5qjTE/WrufGe/WXEEgsFEaXnJ/w+BPMhugL/+PxPIrlGyj/jht+SZadqqplOirZdH18FRbCi0iB7egcl4wnptIfLorgmGDMyn+ZiljHIlqbRdtBnKyE2GyMqpxfoliU3" Mar 25 23:26:44 katarynka go-librespot[21055]: time="2026-03-25T23:26:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:44 katarynka go-librespot[21055]: time="2026-03-25T23:26:44+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:44 katarynka go-librespot[21055]: time="2026-03-25T23:26:44+01:00" level=debug msg="completed challenge" Mar 25 23:26:44 katarynka go-librespot[21055]: time="2026-03-25T23:26: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 25 23:26:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:44 katarynka volumio[20816]: info: Starting Shairport Sync Mar 25 23:26:44 katarynka volumio[20816]: info: Starting Shairport Sync Mar 25 23:26:44 katarynka volumio[20816]: info: Starting Shairport Sync Mar 25 23:26:44 katarynka sudo[21070]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:26:44 katarynka sudo[21070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:44 katarynka sudo[21072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:26:44 katarynka sudo[21072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:44 katarynka sudo[21078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 23:26:44 katarynka sudo[21078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:44 katarynka sudo[21074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:26:44 katarynka sudo[21074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:44 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 23:26:44 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 23:26:44 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:26:44 katarynka systemd[1]: shairport-sync.service: Consumed 2.223s CPU time. Mar 25 23:26:44 katarynka sudo[21078]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:44 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:26:45 katarynka sudo[21070]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:45 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 23:26:45 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 23:26:45 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:26:45 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:26:45 katarynka sudo[21072]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:45 katarynka sudo[21074]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:45 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 23:26:45 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 23:26:45 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 23:26:45 katarynka volumio[20816]: info: Shairport-Sync Started Mar 25 23:26:45 katarynka volumio[20816]: Error adding Membership: Error: addMembership EINVAL Mar 25 23:26:45 katarynka volumio[20816]: info: Upmpdcli Daemon Started Mar 25 23:26:45 katarynka volumio[20816]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 23:26:45 katarynka volumio[20816]: info: Shairport-Sync Started Mar 25 23:26:45 katarynka volumio[20816]: info: Shairport-Sync Started Mar 25 23:26:45 katarynka volumio[20816]: info: CoreCommandRouter::volumioGetState Mar 25 23:26:45 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:26:47 katarynka volumio[20816]: info: go-librespot daemon successfully initialized Mar 25 23:26:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Mar 25 23:26:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:47 katarynka go-librespot[21117]: go-librespot daemon starting... Mar 25 23:26:47 katarynka go-librespot[21118]: time="2026-03-25T23:26:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:47 katarynka go-librespot[21118]: time="2026-03-25T23:26:47+01:00" level=debug msg="app state loaded" Mar 25 23:26:47 katarynka go-librespot[21118]: time="2026-03-25T23:26:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:47 katarynka go-librespot[21118]: time="2026-03-25T23:26:47+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 25 23:26:47 katarynka go-librespot[21118]: time="2026-03-25T23:26:47+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 25 23:26:47 katarynka go-librespot[21118]: time="2026-03-25T23:26:47+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 25 23:26:48 katarynka go-librespot[21118]: time="2026-03-25T23:26:48+01:00" level=info msg="zeroconf server listening on port 46557" Mar 25 23:26:48 katarynka go-librespot[21118]: time="2026-03-25T23:26:48+01:00" level=debug msg="obtained new client token: AADqi4SxNuwe+EDhVcl0ROLDr+LvmHNT2IIG9zzQAmtfiQ347Um9t39xbMiymhqdkyMmJKA36cB13jyzFW6Ei3pk8gUlJ/6QDrXnMQ4659p1WEJigNMZSawUR8IJHFwRwjdDfsOMBATEGEqMcU+tLvV7apIGh2no1WvrLcrC0807BeXI9epmeL7LSOHg9/TBtBPjpnqFQa8kENbdn1ggdKWUs7k8a2PgMsfkllCC/ZdSahs9IFHAY78a" Mar 25 23:26:48 katarynka mpd[21020]: 2026-03-25T23:26:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 23:26:48 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 23:26:48 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 23:26:48 katarynka sudo[20984]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:48 katarynka sudo[20974]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:48 katarynka go-librespot[21118]: time="2026-03-25T23:26:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:48 katarynka volumio[20816]: info: Completed starting Core Plugins Mar 25 23:26:48 katarynka volumio[20816]: info: ------------------------------------------- Mar 25 23:26:48 katarynka volumio[20816]: info: ----- MyVolumio plugins startup ---- Mar 25 23:26:48 katarynka volumio[20816]: info: ------------------------------------------- Mar 25 23:26:48 katarynka volumio[20816]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 23:26:48 katarynka go-librespot[21118]: time="2026-03-25T23:26:48+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:48 katarynka go-librespot[21118]: time="2026-03-25T23:26:48+01:00" level=debug msg="completed challenge" Mar 25 23:26:48 katarynka go-librespot[21118]: time="2026-03-25T23:26:48+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 25 23:26:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:48 katarynka volumio[20816]: error: MPD error: The expression evaluated to a falsy value: Mar 25 23:26:48 katarynka volumio[20816]: assert.ok(self.idling) Mar 25 23:26:48 katarynka volumio[20816]: error: The expression evaluated to a falsy value: Mar 25 23:26:48 katarynka volumio[20816]: assert.ok(self.idling) Mar 25 23:26:48 katarynka volumio[20816]: error: updateQueue error: null Mar 25 23:26:48 katarynka volumio[20816]: info: MPD running with PID21020 Mar 25 23:26:48 katarynka volumio[20816]: ,establishing connection Mar 25 23:26:48 katarynka volumio[20816]: error: updateQueue error: null Mar 25 23:26:50 katarynka volumio[20816]: info: Initializing connection to go-librespot Websocket Mar 25 23:26:50 katarynka volumio[20816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 23:26:51 katarynka sudo[21149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 23:26:51 katarynka sudo[21149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:51 katarynka sudo[21151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 23:26:51 katarynka sudo[21151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:26:51 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Mar 25 23:26:51 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:51 katarynka go-librespot[21154]: go-librespot daemon starting... Mar 25 23:26:51 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 23:26:51 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 23:26:51 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 23:26:51 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 23:26:51 katarynka sudo[21151]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:51 katarynka sudo[21149]: pam_unix(sudo:session): session closed for user root Mar 25 23:26:51 katarynka go-librespot[21155]: time="2026-03-25T23:26:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:51 katarynka go-librespot[21155]: time="2026-03-25T23:26:51+01:00" level=debug msg="app state loaded" Mar 25 23:26:51 katarynka mpd_monitor.sh[21161]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 23:26:51 katarynka volumio[20816]: info: Successfully started MPD Monitor Mar 25 23:26:51 katarynka volumio[20816]: info: Successfully started MPD Monitor Mar 25 23:26:51 katarynka go-librespot[21155]: time="2026-03-25T23:26:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:51 katarynka go-librespot[21155]: time="2026-03-25T23:26:51+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 25 23:26:51 katarynka go-librespot[21155]: time="2026-03-25T23:26:51+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 25 23:26:51 katarynka go-librespot[21155]: time="2026-03-25T23:26:51+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 25 23:26:51 katarynka go-librespot[21155]: time="2026-03-25T23:26:51+01:00" level=info msg="zeroconf server listening on port 39097" Mar 25 23:26:52 katarynka go-librespot[21155]: time="2026-03-25T23:26:52+01:00" level=debug msg="obtained new client token: AAAtiMoHwtLcr0jPaB5usCwpZoSl3Q+QQ2bLQIUPpz6MPb+6wQp58O8Jw9qwcYHi3X0ROvtJ1h8ols8Bzo+z5xgj9gg5y3OBeJDho5ctJN3nOFCGndcs+Bc+X7hbp6hg/OagJifYIU0Jj0d6haujZ/hP05oOPTboc4a3BoZDcomAl6/I7skKJH9W8OUJAYSQA9FQ1OEw/yym0Bm4Zy/kFX3k5rgLLiVTdTZb6u8/ITQPN7H+jrwvv8Aq" Mar 25 23:26:52 katarynka go-librespot[21155]: time="2026-03-25T23:26:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:52 katarynka go-librespot[21155]: time="2026-03-25T23:26:52+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:52 katarynka go-librespot[21155]: time="2026-03-25T23:26:52+01:00" level=debug msg="completed challenge" Mar 25 23:26:52 katarynka go-librespot[21155]: time="2026-03-25T23:26:52+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 25 23:26:52 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:52 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:53 katarynka volumio[20816]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 23:26:53 katarynka volumio[20816]: info: Initializing connection to go-librespot Websocket Mar 25 23:26:53 katarynka volumio[20816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 23:26:55 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Mar 25 23:26:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:26:55 katarynka go-librespot[21166]: go-librespot daemon starting... Mar 25 23:26:55 katarynka go-librespot[21167]: time="2026-03-25T23:26:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:26:55 katarynka go-librespot[21167]: time="2026-03-25T23:26:55+01:00" level=debug msg="app state loaded" Mar 25 23:26:55 katarynka go-librespot[21167]: time="2026-03-25T23:26:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:26:55 katarynka go-librespot[21167]: time="2026-03-25T23:26:55+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 25 23:26:55 katarynka go-librespot[21167]: time="2026-03-25T23:26:55+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 25 23:26:55 katarynka go-librespot[21167]: time="2026-03-25T23:26:55+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 25 23:26:55 katarynka go-librespot[21167]: time="2026-03-25T23:26:55+01:00" level=info msg="zeroconf server listening on port 41121" Mar 25 23:26:56 katarynka go-librespot[21167]: time="2026-03-25T23:26:56+01:00" level=debug msg="obtained new client token: AABg/Jwe8102VIVsUB++RtTeMgcqEMEyN2c79sdDyHLygd8K/AiE+HvUWlx9VsaslWP2HzgEiDiaZtOiNFa4yDajlDP3z6AtlX3azzWsPvhLxxo3QLGr+1kNJJg7bF+GZb9vM1QWLRC8PAIVfLCjWDQUx8ULMNssBc+Sue1hRM5KHilIz1ratBi4ucErlsYagBk08LFkSpA8+12LCYfGGkFeB/P07TBWsuurK0inDqui7qt4EbHC04DY" Mar 25 23:26:56 katarynka go-librespot[21167]: time="2026-03-25T23:26:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:26:56 katarynka volumio[20816]: info: Initializing connection to go-librespot Websocket Mar 25 23:26:56 katarynka go-librespot[21167]: time="2026-03-25T23:26:56+01:00" level=debug msg="new websocket client" Mar 25 23:26:56 katarynka volumio[20816]: info: Connection to go-librespot Websocket established Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 23:26:56 katarynka volumio[20816]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 23:26:56 katarynka volumio[20816]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 23:26:56 katarynka volumio[20816]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 23:26:56 katarynka volumio[20816]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 23:26:56 katarynka volumio[20816]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 23:26:56 katarynka volumio[20816]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 23:26:56 katarynka volumio[20816]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 23:26:56 katarynka volumio[20816]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 23:26:56 katarynka go-librespot[21167]: time="2026-03-25T23:26:56+01:00" level=debug msg="completed keyexchange" Mar 25 23:26:56 katarynka go-librespot[21167]: time="2026-03-25T23:26:56+01:00" level=debug msg="completed challenge" Mar 25 23:26:56 katarynka go-librespot[21167]: time="2026-03-25T23:26: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 25 23:26:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:26:57 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:26:58 katarynka volumio[20816]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 23:26:58 katarynka volumio[20816]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 23:26:58 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:58 katarynka volumio[20816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:26:58 katarynka volumio[20816]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 23:26:58 katarynka volumio[20816]: info: MyVolumio login type: Token Mar 25 23:26:58 katarynka volumio[20816]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 23:26:58 katarynka volumio[20816]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 23:27:00 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Mar 25 23:27:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:00 katarynka go-librespot[21174]: go-librespot daemon starting... Mar 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+01:00" level=debug msg="app state loaded" Mar 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:00 katarynka volumio[20816]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 23:27:00 katarynka volumio[20816]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 23:27:00 katarynka volumio[20816]: info: Streaming services startup Mar 25 23:27:00 katarynka volumio[20816]: info: Starting Streaming Daemon Mar 25 23:27:00 katarynka sudo[21184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 23:27:00 katarynka sudo[21184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:00 katarynka volumio[20816]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 23:27:00 katarynka sudo[21184]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+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 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+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 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+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 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+01:00" level=info msg="zeroconf server listening on port 41313" Mar 25 23:27:00 katarynka volumio[20816]: info: Getting Spotify volume Mar 25 23:27:00 katarynka volumio[20816]: info: Connection to go-librespot Websocket closed Mar 25 23:27:00 katarynka volumio[20816]: error: Cannot start Volumio Streaming Daemon Mar 25 23:27:00 katarynka volumio[20816]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 23:27:00 katarynka volumio[20816]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 23:27:00 katarynka go-librespot[21175]: time="2026-03-25T23:27:00+01:00" level=debug msg="obtained new client token: AAC/wwIesVNlVUQBelJKnAsHO9kX2j8P13QsHGGCUpDDalhXSCRNw4WtNUyutc25b96IB7O0a2IfjCViFUEIHAsTzj/iKSjtOXv1s0zOsiM9fvbRa/rv7beC5eoxgE/sW4f3dUyk7/+bWQ8OFY2SMCVmLOb7v6WTsG9N9I5py7M+N8WoFUNxAc3TaXp8sGSvNl8O3llnZBjleRnSTOQKv9r+KCuCf9KC/oACrGXt2lghTHmZiQhUq/kv1iY=" Mar 25 23:27:00 katarynka volumio[20816]: 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 25 23:27:01 katarynka go-librespot[21175]: time="2026-03-25T23:27:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:01 katarynka volumio[20816]: info: CoreCommandRouter::volumioGetState Mar 25 23:27:01 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:01 katarynka volumio[20816]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 25 23:27:01 katarynka volumio[20816]: SPOTIFY: SPOTIFY VOLUME undefined Mar 25 23:27:01 katarynka volumio[20816]: SPOTIFY: VOLUMIO VOLUME 96 Mar 25 23:27:01 katarynka volumio[20816]: info: Aligning Spotify Volume to Volumio Volume Mar 25 23:27:01 katarynka volumio[20816]: info: CoreCommandRouter::volumioGetState Mar 25 23:27:01 katarynka volumio[20816]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:01 katarynka volumio[20816]: info: Setting Spotify Volume from Volumio: 96 Mar 25 23:27:01 katarynka go-librespot[21175]: time="2026-03-25T23:27:01+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:01 katarynka go-librespot[21175]: time="2026-03-25T23:27:01+01:00" level=debug msg="completed challenge" Mar 25 23:27:01 katarynka volumio[20816]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 23:27:01 katarynka go-librespot[21175]: time="2026-03-25T23:27:01+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 25 23:27:01 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:01 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:01 katarynka volumio[20816]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 23:27:01 katarynka volumio[20816]: Error: socket hang up Mar 25 23:27:01 katarynka volumio[20816]: at connResetException (node:internal/errors:720:14) Mar 25 23:27:01 katarynka volumio[20816]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 23:27:01 katarynka volumio[20816]: at Socket.emit (node:events:526:35) Mar 25 23:27:01 katarynka volumio[20816]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 23:27:01 katarynka volumio[20816]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 23:27:01 katarynka volumio[20816]: code: 'ECONNRESET', Mar 25 23:27:01 katarynka volumio[20816]: response: undefined Mar 25 23:27:01 katarynka volumio[20816]: } Mar 25 23:27:01 katarynka volumio[20816]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 23:27:03 katarynka sudo[21219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 23:26' Mar 25 23:27:03 katarynka sudo[21219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:03 katarynka sudo[21219]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:03 katarynka volumio-remote-updater[686]: [2026-03-25 23:27:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 23:27:03 katarynka volumio-remote-updater[686]: [2026-03-25 23:27:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 23:27:03 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:03 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 23:27:03 katarynka systemd[1]: volumio.service: Consumed 49.230s CPU time. Mar 25 23:27:03 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 23:27:03 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 23:27:03 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 402. Mar 25 23:27:03 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 23:27:03 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 23:27:03 katarynka systemd[1]: volumio.service: Consumed 49.230s CPU time. Mar 25 23:27:03 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 23:27:04 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 23:27:04 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Mar 25 23:27:04 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:05 katarynka go-librespot[21248]: go-librespot daemon starting... Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=debug msg="app state loaded" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+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 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+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 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+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 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=info msg="zeroconf server listening on port 45643" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=debug msg="obtained new client token: AAAe5M/yjM1+vHEkn9caEFeHy1xlOdCb34DwpurrIlseBzxkpC95DVgV1NThktXx6XZIkS6BuA64JAs7YGJjUEE9xToXLuwZSHXmIQtq39660L24RwbxApZNZmmTLZ5y91mTmsy4B+7LaEIyMTgS2nLFTqYsoVWZpkJIhrNNXkIl6HFl4h9f62lsOjcaHsm7QhrjSKqfdQvKQApvHu+wcL7w7UrSVF3G2dTwHDZ7t/feggPQHRIXFSzj5Fg=" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+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 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+01:00" level=debug msg="completed challenge" Mar 25 23:27:05 katarynka go-librespot[21249]: time="2026-03-25T23:27:05+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 25 23:27:05 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:05 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:07 katarynka volumio[21232]: info: ------------------------------------------- Mar 25 23:27:07 katarynka volumio[21232]: info: ----- Volumio3 ---- Mar 25 23:27:07 katarynka volumio[21232]: info: ------------------------------------------- Mar 25 23:27:07 katarynka volumio[21232]: info: ----- System startup ---- Mar 25 23:27:07 katarynka volumio[21232]: info: ------------------------------------------- Mar 25 23:27:08 katarynka volumio-remote-updater[686]: [2026-03-25 23:27:08] [connect] Successful connection Mar 25 23:27:08 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Mar 25 23:27:08 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:08 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:09 katarynka go-librespot[21262]: go-librespot daemon starting... Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=debug msg="app state loaded" Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:09 katarynka volumio[21232]: info: MYVOLUMIO Environment detected Mar 25 23:27:09 katarynka volumio[21232]: info: Plugin folders cleanup Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning into folder /volumio/app/plugins/ Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning category audio_interface Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning category miscellanea Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning category music_service Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning category plugins.json Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning category system_controller Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning category user_interface Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning into folder /data/plugins/ Mar 25 23:27:09 katarynka volumio[21232]: info: Scanning category music_service Mar 25 23:27:09 katarynka volumio[21232]: info: Plugin folders cleanup completed Mar 25 23:27:09 katarynka volumio[21232]: info: ------------------------------------------- Mar 25 23:27:09 katarynka volumio[21232]: info: ----- Core plugins startup ---- Mar 25 23:27:09 katarynka volumio[21232]: info: ------------------------------------------- Mar 25 23:27:09 katarynka volumio[21232]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 23:27:09 katarynka volumio[21232]: info: Adding plugin upnp to MyMusic Plugins Mar 25 23:27:09 katarynka volumio[21232]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 23:27:09 katarynka volumio[21232]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 23:27:09 katarynka volumio[21232]: info: Loading plugins from folder /data/plugins/ Mar 25 23:27:09 katarynka volumio[21232]: info: Loading plugin "system"... Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+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 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+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 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+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 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=info msg="zeroconf server listening on port 35047" Mar 25 23:27:09 katarynka volumio[21232]: info: Loading plugin "appearance"... Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=debug msg="obtained new client token: AAAXFcLrfzfi2xG88YYfgj2Zj2yTzAppMWdqB1Vmb83DZJst2Z7d+tPPV6meDFux1GFc9hgHD4F/GreJ73dwdsr8tSrO423g7x3k8fMxD6y58k0TyD79EI4tCgE7PXrQYyhqGRj3GVhj+cv0iyr321iwGT0VfnrIuWKWvdlDx6iAjELJ8Wi7HwYtEUDDAAYhSycltOlWIwOw54HegbaBTSshhxxQoiqcvtsADHjGuBpQdxpwH2z1KmtT/eY=" Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+01:00" level=debug msg="completed challenge" Mar 25 23:27:09 katarynka go-librespot[21263]: time="2026-03-25T23:27:09+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 25 23:27:09 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:09 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:11 katarynka volumio[21232]: info: Loading plugin "network"... Mar 25 23:27:11 katarynka volumio[21232]: info: Refreshing Cached IP Addresses Mar 25 23:27:11 katarynka sudo[21280]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 23:27:11 katarynka sudo[21280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:11 katarynka sudo[21280]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:11 katarynka sudo[21282]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 23:27:11 katarynka sudo[21282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:11 katarynka volumio[21232]: info: Loading plugin "services"... Mar 25 23:27:11 katarynka sudo[21282]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:11 katarynka volumio[21232]: info: Loading plugin "alsa_controller"... Mar 25 23:27:11 katarynka sudo[21290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 23:27:11 katarynka sudo[21290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:11 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 23:27:11 katarynka volumio[21232]: info: Loading plugin "wizard"... Mar 25 23:27:11 katarynka volumio[21232]: info: Loading plugin "networkfs"... Mar 25 23:27:11 katarynka volumio[21232]: info: Starting Udev Watcher for removable devices Mar 25 23:27:12 katarynka volumio[21232]: info: Ignoring mount for partition: boot Mar 25 23:27:12 katarynka volumio[21232]: info: Ignoring mount for partition: volumio Mar 25 23:27:12 katarynka volumio[21232]: info: Ignoring mount for partition: volumio_data Mar 25 23:27:12 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 23:27:12 katarynka volumio[21232]: info: Loading plugin "volumio_command_line_client"... Mar 25 23:27:12 katarynka volumio[21232]: info: Loading plugin "upnp"... Mar 25 23:27:12 katarynka volumio[21232]: info: [1774477632042] Starting Upmpd Daemon Mar 25 23:27:12 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 23:27:12 katarynka volumio[21232]: info: Loading plugin "my_music"... Mar 25 23:27:12 katarynka volumio[21232]: info: Loading plugin "mpd"... Mar 25 23:27:12 katarynka sudo[21290]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:12 katarynka volumio[21232]: info: Loading plugin "upnp_browser"... Mar 25 23:27:12 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Mar 25 23:27:12 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:13 katarynka go-librespot[21313]: go-librespot daemon starting... Mar 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+01:00" level=debug msg="app state loaded" Mar 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+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 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+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 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+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 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+01:00" level=info msg="zeroconf server listening on port 32997" Mar 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+01:00" level=debug msg="obtained new client token: AADPq3sNyOvyyFF2OgUsRiv8vqhOcf8gSUAtBpxUp2Ay0azWt/8QOnidYDseO2ZchGNE9mVNdV9zPD9jGdei970YmP05reEWKOPDsynBBf5f8+SnN2dBO6S48x9iwZ1Isa5grn8ObfRdOXdgGlMQJeKaqE1vjnkUbntzqclS7YSlwBXzJWYDUHUBSyppGMfcLrGM4BkAuBGEJ/6wgODqmblv3ARAzOTXmO33r9KLehbrjaEktee1oGJbwQQ=" Mar 25 23:27:13 katarynka go-librespot[21314]: time="2026-03-25T23:27:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:14 katarynka go-librespot[21314]: time="2026-03-25T23:27:14+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:14 katarynka go-librespot[21314]: time="2026-03-25T23:27:14+01:00" level=debug msg="completed challenge" Mar 25 23:27:14 katarynka go-librespot[21314]: time="2026-03-25T23:27: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 25 23:27:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:15 katarynka volumio[21232]: info: Starting UPNP Browser Mar 25 23:27:15 katarynka volumio[21232]: info: Loading plugin "alarm-clock"... Mar 25 23:27:16 katarynka volumio[21232]: info: Loading plugin "airplay_emulation"... Mar 25 23:27:16 katarynka volumio[21232]: info: Starting Shairport Sync Mar 25 23:27:16 katarynka volumio[21232]: info: Loading plugin "last_100"... Mar 25 23:27:16 katarynka volumio[21232]: info: Loading plugin "webradio"... Mar 25 23:27:16 katarynka volumio[21232]: info: Loading plugin "i2s_dacs"... Mar 25 23:27:16 katarynka volumio[21232]: info: Loading plugin "volumiodiscovery"... Mar 25 23:27:16 katarynka volumio[21232]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 23:27:16 katarynka volumio[21232]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:27:16 katarynka volumio[21232]: *** WARNING *** For more information see Mar 25 23:27:16 katarynka volumio[21232]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 23:27:16 katarynka volumio[21232]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:27:16 katarynka volumio[21232]: *** WARNING *** For more information see Mar 25 23:27:16 katarynka node[21232]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 23:27:16 katarynka node[21232]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:27:16 katarynka node[21232]: *** WARNING *** For more information see Mar 25 23:27:16 katarynka node[21232]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 23:27:16 katarynka node[21232]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 23:27:16 katarynka node[21232]: *** WARNING *** For more information see Mar 25 23:27:16 katarynka volumio[21232]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 23:27:16 katarynka volumio[21232]: info: Discovery: Started advertising with name: katarynka Mar 25 23:27:16 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 23:27:16 katarynka volumio[21232]: info: Loading plugin "spop"... Mar 25 23:27:17 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Mar 25 23:27:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:17 katarynka go-librespot[21324]: go-librespot daemon starting... Mar 25 23:27:17 katarynka go-librespot[21325]: time="2026-03-25T23:27:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:17 katarynka go-librespot[21325]: time="2026-03-25T23:27:17+01:00" level=debug msg="app state loaded" Mar 25 23:27:17 katarynka go-librespot[21325]: time="2026-03-25T23:27:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27: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-gew1.spotify.com:80]" Mar 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+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 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+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 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+01:00" level=info msg="zeroconf server listening on port 37841" Mar 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+01:00" level=debug msg="obtained new client token: AABQwPzTk9x5zcmS6PSf3BvnrCXjdRlrlNHFdqB12+VDPm08QAi1lJMNy0L4shfWTioC+/C1Ha3H2WgV5TY0w7d8SMdrsecla2z6QdYPKiQ8jA3Va5rio4RKHrEWm444aYKclCXJyobfxsAmUavahzNv67Xf1F3CfwrumcPmdKfJTZbKwi3mauapI5q8x95KpClyqCWo2njtj7hsLgf8QbY+GOKDV6a+xCFRdcN88FV9OyKAGjHqHnScyFw=" Mar 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+01:00" level=debug msg="completed challenge" Mar 25 23:27:18 katarynka volumio[21232]: info: Loading plugin "outputs"... Mar 25 23:27:18 katarynka go-librespot[21325]: time="2026-03-25T23:27:18+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 25 23:27:18 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:18 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:18 katarynka volumio[21232]: info: Loading plugin "albumart"... Mar 25 23:27:18 katarynka volumio[21232]: info: Plugin example_plugin is not enabled Mar 25 23:27:18 katarynka volumio[21232]: info: Loading plugin "inputs"... Mar 25 23:27:18 katarynka volumio[21232]: info: Loading plugin "updater_comm"... Mar 25 23:27:18 katarynka volumio[21232]: info: Plugin mpdemulation is not enabled Mar 25 23:27:18 katarynka volumio[21232]: info: Loading plugin "rest_api"... Mar 25 23:27:19 katarynka volumio[21232]: info: Loading plugin "websocket"... Mar 25 23:27:19 katarynka volumio[21232]: info: Starting Socket.io Server version 1.7.4 Mar 25 23:27:19 katarynka volumio[21232]: info: Loading i18n strings for locale pl Mar 25 23:27:19 katarynka volumio[21232]: Updating browse sources language Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::initPlayerControls Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: Express server listening on port 3000 Mar 25 23:27:19 katarynka volumio[21232]: [Metrics] WebUI: 12s 585.64ms Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::resetVolumioState Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::getcurrentVolume Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 23:27:19 katarynka volumio[21232]: info: Cannot read play queue from file Mar 25 23:27:19 katarynka volumio[21232]: info: Volumio Network Manager: Network status updated: 2 Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:19 katarynka volumio[21232]: info: Setting Device type: Raspberry PI Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::setRepeat null single undefined Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::pushState Mar 25 23:27:19 katarynka volumio[21232]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::volumioPushState Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::setRandom null Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::pushState Mar 25 23:27:19 katarynka volumio[21232]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::volumioPushState Mar 25 23:27:19 katarynka volumio[21232]: info: Completed loading Core Plugins Mar 25 23:27:19 katarynka volumio[21332]: Forking 3 albumart workers Mar 25 23:27:19 katarynka volumio[21232]: info: Preparing to generate the ALSA configuration file Mar 25 23:27:19 katarynka volumio[21232]: info: VolumeController:: Volume=96 Mute =false Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::pushState Mar 25 23:27:19 katarynka volumio[21232]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::volumioPushState Mar 25 23:27:19 katarynka volumio[21232]: info: CoreStateMachine::updateTrackBlock Mar 25 23:27:19 katarynka volumio[21232]: info: CorePlayQueue::getTrackBlock Mar 25 23:27:19 katarynka volumio[21232]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 23:27:20 katarynka volumio[21232]: info: Asound.conf file unchanged, so no further update is needed Mar 25 23:27:20 katarynka volumio[21232]: info: Output device has changed, restarting MPD Mar 25 23:27:20 katarynka volumio[21232]: info: Output device has changed, restarting Shairport Sync Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:20 katarynka sudo[21388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 23:27:20 katarynka sudo[21388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:20 katarynka sudo[21386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 23:27:20 katarynka sudo[21386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:20 katarynka sudo[21386]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:20 katarynka volumio[21232]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 23:27:20 katarynka volumio[21232]: info: ___________ START PLUGINS ___________ Mar 25 23:27:20 katarynka volumio[21232]: info: ControllerMpd::onStart: Initializing MPD Mar 25 23:27:20 katarynka volumio[21232]: info: Creating MPD Configuration file Mar 25 23:27:20 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 23:27:20 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 23:27:20 katarynka volumio[21232]: info: [1774477640408] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:27:20 katarynka volumio[21232]: info: UPNP Browser: Client initialized successfully Mar 25 23:27:20 katarynka sudo[21400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 23:27:20 katarynka sudo[21400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:20 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:20 katarynka sudo[21398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 23:27:20 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 23:27:20 katarynka sudo[21398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:20 katarynka systemd[1]: mpd.service: Consumed 7.709s CPU time. Mar 25 23:27:20 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 23:27:20 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 23:27:20 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 23:27:20 katarynka sudo[21398]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:20 katarynka volumio[21232]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:20 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 23:27:20 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 23:27:20 katarynka volumio[21232]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 23:27:20 katarynka volumio[21232]: info: [1774477640751] CoreMusicLibrary::Adding element Last_100 Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 23:27:20 katarynka volumio[21232]: info: [1774477640770] CoreMusicLibrary::Adding element Webradio Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 23:27:20 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 23:27:20 katarynka volumio[21232]: info: Initializing BBC Radios Mar 25 23:27:21 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 23:27:21 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:21 katarynka volumio[21232]: info: Creating Spotify config file Mar 25 23:27:21 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:21 katarynka sudo[21410]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 23:27:21 katarynka sudo[21410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 23:27:21 katarynka sudo[21410]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:21 katarynka volumio-remote-updater[686]: [2026-03-25 23:27:21] [connect] Successful connection Mar 25 23:27:21 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Mar 25 23:27:21 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:21 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:21 katarynka go-librespot[21428]: go-librespot daemon starting... Mar 25 23:27:21 katarynka go-librespot[21430]: time="2026-03-25T23:27:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:22 katarynka go-librespot[21430]: time="2026-03-25T23:27:22+01:00" level=info msg="zeroconf server listening on port 42845" Mar 25 23:27:22 katarynka volumio[21232]: info: Volumio Calling Home Mar 25 23:27:23 katarynka volumio[21232]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 23:27:23 katarynka volumio[21232]: info: Discovery: Found device katarynka Mar 25 23:27:23 katarynka volumio[21232]: info: CoreCommandRouter::volumioGetState Mar 25 23:27:23 katarynka volumio[21232]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:23 katarynka sudo[21455]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 23:27:23 katarynka sudo[21455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:23 katarynka sudo[21457]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 23:27:23 katarynka sudo[21455]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:23 katarynka sudo[21457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:23 katarynka volumio[21232]: info: MPD Permissions set Mar 25 23:27:23 katarynka volumio[21232]: info: MPD Permissions set Mar 25 23:27:23 katarynka volumio[21232]: info: VolumeController:: Volume=96 Mute =false Mar 25 23:27:23 katarynka volumio[21232]: info: CoreStateMachine::pushState Mar 25 23:27:23 katarynka volumio[21232]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:23 katarynka volumio[21232]: info: CoreCommandRouter::volumioPushState Mar 25 23:27:23 katarynka volumio[21232]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 23:27:23 katarynka volumio[21232]: info: Discovery: Found device katarynka Mar 25 23:27:23 katarynka volumio[21232]: info: CoreCommandRouter::volumioGetState Mar 25 23:27:23 katarynka volumio[21232]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:23 katarynka sudo[21457]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:23 katarynka volumio-remote-updater[686]: [2026-03-25 23:27:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774477641 101 Mar 25 23:27:23 katarynka volumio[21232]: 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 25 23:27:23 katarynka volumio[21232]: info: Spotify config file written Mar 25 23:27:23 katarynka volumio[21353]: Starting albumart workers Mar 25 23:27:23 katarynka volumio[21354]: Starting albumart workers Mar 25 23:27:23 katarynka sudo[21461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 23:27:23 katarynka sudo[21461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:23 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 23:27:24 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 23:27:24 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:24 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:24 katarynka go-librespot[21464]: go-librespot daemon starting... Mar 25 23:27:24 katarynka sudo[21461]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+01:00" level=debug msg="app state loaded" Mar 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:24 katarynka volumio[21232]: 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 25 23:27:24 katarynka volumio[21232]: info: Volumio called home Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:24 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+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 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+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 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+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 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+01:00" level=info msg="zeroconf server listening on port 41163" Mar 25 23:27:24 katarynka volumio[21232]: info: No need to fix Spotify hosts Mar 25 23:27:24 katarynka volumio[21355]: Starting albumart workers Mar 25 23:27:24 katarynka go-librespot[21465]: time="2026-03-25T23:27:24+01:00" level=debug msg="obtained new client token: AACwZahNsUm7FS/xmO7S8N7lipyFP0JTZOh7Ku5QLtMsgm5czC/nOHwDcXtmeB7F1t7zyMgQFrUuBntgD6CWDmBgKL7/VnJQuE3p/mXG91ruti7YATh9sHN9OYu3WpD8P1U0rDBKcd2akALmNn4kXaAddTUHv5rYt6iVU7sB/ZnenkRAEglmiIEK9NwS6+BFwqaypqkqcGIuo+fLTWebU2n4POammErZ+O7FZf4Hm34jr719fpKKsXIEyf0=" Mar 25 23:27:25 katarynka go-librespot[21465]: time="2026-03-25T23:27:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:25 katarynka go-librespot[21465]: time="2026-03-25T23:27:25+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:25 katarynka go-librespot[21465]: time="2026-03-25T23:27:25+01:00" level=debug msg="completed challenge" Mar 25 23:27:25 katarynka go-librespot[21465]: time="2026-03-25T23:27:25+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 25 23:27:25 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:25 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:25 katarynka volumio[21232]: info: Starting Shairport Sync Mar 25 23:27:25 katarynka volumio[21232]: info: Starting Shairport Sync Mar 25 23:27:25 katarynka volumio[21232]: info: Starting Shairport Sync Mar 25 23:27:25 katarynka sudo[21484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:27:25 katarynka sudo[21484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:25 katarynka sudo[21486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:27:25 katarynka sudo[21486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:25 katarynka sudo[21488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 23:27:25 katarynka sudo[21488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:25 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 23:27:25 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 23:27:25 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:27:25 katarynka systemd[1]: shairport-sync.service: Consumed 2.381s CPU time. Mar 25 23:27:25 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:27:25 katarynka sudo[21484]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:25 katarynka sudo[21491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 23:27:25 katarynka sudo[21491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:26 katarynka sudo[21486]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:26 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 23:27:26 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 23:27:26 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:27:26 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 23:27:26 katarynka sudo[21488]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:26 katarynka volumio[21232]: info: Shairport-Sync Started Mar 25 23:27:26 katarynka sudo[21491]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:26 katarynka volumio[21232]: Error adding Membership: Error: addMembership EINVAL Mar 25 23:27:26 katarynka volumio[21232]: info: Shairport-Sync Started Mar 25 23:27:26 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 23:27:26 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 23:27:26 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 23:27:26 katarynka volumio[21232]: info: Upmpdcli Daemon Started Mar 25 23:27:26 katarynka volumio[21232]: info: Shairport-Sync Started Mar 25 23:27:26 katarynka volumio[21232]: info: CoreCommandRouter::volumioGetState Mar 25 23:27:26 katarynka volumio[21232]: info: CorePlayQueue::getTrack 0 Mar 25 23:27:26 katarynka volumio[21232]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 23:27:28 katarynka volumio[21232]: info: go-librespot daemon successfully initialized Mar 25 23:27:28 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 23:27:28 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:28 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:28 katarynka go-librespot[21541]: go-librespot daemon starting... Mar 25 23:27:28 katarynka go-librespot[21542]: time="2026-03-25T23:27:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:28 katarynka go-librespot[21542]: time="2026-03-25T23:27:28+01:00" level=debug msg="app state loaded" Mar 25 23:27:28 katarynka go-librespot[21542]: time="2026-03-25T23:27:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+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 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+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 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+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 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+01:00" level=info msg="zeroconf server listening on port 35981" Mar 25 23:27:29 katarynka mpd[21427]: 2026-03-25T23:27:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 23:27:29 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 23:27:29 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 23:27:29 katarynka sudo[21388]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:29 katarynka sudo[21400]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+01:00" level=debug msg="obtained new client token: AACO/Q8F8kdjMOFX/524PU51AFy3doOG0ur7guP7eQOJE6cOantBvRyQ2n8A/WR4AYZ749D2+izTIsNZXBfp32UCvv9rC1F88qL/iJ2WUvkzo1iUEGrIxbenZK32ZZv4KD2sy6fLOSFWf0T7C0Zvp7dEQn0xMGR5ijF4GafVxGPlEWuIL8US5tTjUArgFR+qyVJQxYT17OeZx74c8cAxGSR4leyB9ryLvz7Rdeu37m1g/78+RvZ9xPBB" Mar 25 23:27:29 katarynka volumio[21232]: info: Completed starting Core Plugins Mar 25 23:27:29 katarynka volumio[21232]: info: ------------------------------------------- Mar 25 23:27:29 katarynka volumio[21232]: info: ----- MyVolumio plugins startup ---- Mar 25 23:27:29 katarynka volumio[21232]: info: ------------------------------------------- Mar 25 23:27:29 katarynka volumio[21232]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+01:00" level=debug msg="completed challenge" Mar 25 23:27:29 katarynka go-librespot[21542]: time="2026-03-25T23:27:29+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 25 23:27:29 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:29 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:29 katarynka volumio[21232]: error: MPD error: The expression evaluated to a falsy value: Mar 25 23:27:29 katarynka volumio[21232]: assert.ok(self.idling) Mar 25 23:27:29 katarynka volumio[21232]: error: The expression evaluated to a falsy value: Mar 25 23:27:29 katarynka volumio[21232]: assert.ok(self.idling) Mar 25 23:27:29 katarynka volumio[21232]: info: MPD running with PID21427 Mar 25 23:27:29 katarynka volumio[21232]: ,establishing connection Mar 25 23:27:29 katarynka volumio[21232]: error: updateQueue error: null Mar 25 23:27:29 katarynka volumio[21232]: error: updateQueue error: null Mar 25 23:27:31 katarynka volumio[21232]: info: Initializing connection to go-librespot Websocket Mar 25 23:27:31 katarynka volumio[21232]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 23:27:32 katarynka sudo[21571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 23:27:32 katarynka sudo[21571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:32 katarynka sudo[21573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 23:27:32 katarynka sudo[21573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:32 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 23:27:32 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 23:27:32 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 23:27:32 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 23:27:32 katarynka sudo[21571]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:32 katarynka mpd_monitor.sh[21576]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 23:27:32 katarynka volumio[21232]: info: Successfully started MPD Monitor Mar 25 23:27:32 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 23:27:32 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:32 katarynka sudo[21573]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:32 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:32 katarynka volumio[21232]: info: Successfully started MPD Monitor Mar 25 23:27:32 katarynka go-librespot[21581]: go-librespot daemon starting... Mar 25 23:27:32 katarynka go-librespot[21582]: time="2026-03-25T23:27:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:32 katarynka go-librespot[21582]: time="2026-03-25T23:27:32+01:00" level=debug msg="app state loaded" Mar 25 23:27:32 katarynka go-librespot[21582]: time="2026-03-25T23:27:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+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 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+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 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+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 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+01:00" level=info msg="zeroconf server listening on port 33599" Mar 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+01:00" level=debug msg="obtained new client token: AAAEeQ5PP38JM4KVywsoRZ/SdAy/+c12mq1E1xDr3YYosGLcSQ+3Yi/A2IPaqat/Z4oXeBq6uZmbt9E+00X8/eMMfguyi49ixB7n7TKchf87/0A3o7UY9SKvpDTRCbC/LdQ+oh1mh0GqZWMDphkXbxB6RUvDkP5SO8IdmFn6bu3xymRwXAXYmFcMGKbq2+EeEjF3fAq3jQq5Kg+S7NE80vzn21s0HnI6P+KbCv1Sd5UyJNzrc+wTxKeD" Mar 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+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 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+01:00" level=debug msg="completed challenge" Mar 25 23:27:33 katarynka go-librespot[21582]: time="2026-03-25T23:27:33+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 25 23:27:33 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:33 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:34 katarynka volumio[21232]: info: Initializing connection to go-librespot Websocket Mar 25 23:27:34 katarynka volumio[21232]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 23:27:34 katarynka volumio[21232]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 23:27:36 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 23:27:36 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:36 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:36 katarynka go-librespot[21590]: go-librespot daemon starting... Mar 25 23:27:36 katarynka go-librespot[21591]: time="2026-03-25T23:27:36+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:36 katarynka go-librespot[21591]: time="2026-03-25T23:27:36+01:00" level=debug msg="app state loaded" Mar 25 23:27:36 katarynka go-librespot[21591]: time="2026-03-25T23:27:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:36 katarynka go-librespot[21591]: time="2026-03-25T23:27:36+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 25 23:27:36 katarynka go-librespot[21591]: time="2026-03-25T23:27:36+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 25 23:27:36 katarynka go-librespot[21591]: time="2026-03-25T23:27:36+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 25 23:27:36 katarynka go-librespot[21591]: time="2026-03-25T23:27:36+01:00" level=info msg="zeroconf server listening on port 41157" Mar 25 23:27:37 katarynka go-librespot[21591]: time="2026-03-25T23:27:37+01:00" level=debug msg="obtained new client token: AACBFwe5fzRSDF4ntucjJgjoQ+JjDiU50kRr/N5LS+5YemKwX23yE/npHqxCQCVD87upWbm0SMdgHFqm4vpkt8KSDQNmQmKnlUXS4DUrD957iAQ958wYnNKJgWbgUnYBWJe8/0ZYffca+ngT8BgOvR20Hq4TPD28tYUPEYd41DYl2Jv3KPFp//qGjz9580Whn2h5XOMg+4ZnWqIE+tDAbEtxAtQwUOe/hC/Hn8+DpW1JFT6X3277hM60" Mar 25 23:27:37 katarynka go-librespot[21591]: time="2026-03-25T23:27:37+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:37 katarynka volumio[21232]: info: Initializing connection to go-librespot Websocket Mar 25 23:27:37 katarynka go-librespot[21591]: time="2026-03-25T23:27:37+01:00" level=debug msg="new websocket client" Mar 25 23:27:37 katarynka volumio[21232]: info: Connection to go-librespot Websocket established Mar 25 23:27:37 katarynka go-librespot[21591]: time="2026-03-25T23:27:37+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:37 katarynka go-librespot[21591]: time="2026-03-25T23:27:37+01:00" level=debug msg="completed challenge" Mar 25 23:27:37 katarynka go-librespot[21591]: time="2026-03-25T23:27:37+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 25 23:27:37 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:37 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:37 katarynka volumio[21232]: info: Connection to go-librespot Websocket closed Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 23:27:37 katarynka volumio[21232]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 23:27:37 katarynka volumio[21232]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 23:27:37 katarynka volumio[21232]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 23:27:37 katarynka volumio[21232]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 23:27:37 katarynka volumio[21232]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 23:27:37 katarynka volumio[21232]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 23:27:37 katarynka volumio[21232]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 23:27:37 katarynka volumio[21232]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 23:27:39 katarynka volumio[21232]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 23:27:39 katarynka volumio[21232]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 23:27:39 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:39 katarynka volumio[21232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 23:27:39 katarynka volumio[21232]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 23:27:39 katarynka volumio[21232]: info: MyVolumio login type: Token Mar 25 23:27:39 katarynka volumio[21232]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 23:27:39 katarynka volumio[21232]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 23:27:40 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 23:27:40 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:40 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 23:27:40 katarynka go-librespot[21598]: go-librespot daemon starting... Mar 25 23:27:40 katarynka go-librespot[21599]: time="2026-03-25T23:27:40+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 23:27:40 katarynka go-librespot[21599]: time="2026-03-25T23:27:40+01:00" level=debug msg="app state loaded" Mar 25 23:27:40 katarynka go-librespot[21599]: time="2026-03-25T23:27:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+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 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+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 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+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 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+01:00" level=info msg="zeroconf server listening on port 34433" Mar 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+01:00" level=debug msg="obtained new client token: AAA/m20qoH0eb9ynAb0iOfdGIxvoMie1azwr8RyMRGlo3/ioH4YDD55Rbn58ecb3kTM0sFamVhfDy71uK2FOsedwMFlawtj+G0dZol/Ej92xYc8oxF/Mwa3V5uomsp6TFNqIgTryHNVtbiqNuHSXMmcjUru4vAznPu9kdvmQRVl776rr4HbPQw1MyzePK5+Q+sx429+AZuwFKkqlaz/JwFQ6rz9BFx/SccoozbPl0z2DettFxnHGiFV6" Mar 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+01:00" level=debug msg="completed keyexchange" Mar 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+01:00" level=debug msg="completed challenge" Mar 25 23:27:41 katarynka go-librespot[21599]: time="2026-03-25T23:27:41+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 25 23:27:41 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 23:27:41 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 23:27:41 katarynka volumio[21232]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 23:27:41 katarynka volumio[21232]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 23:27:41 katarynka volumio[21232]: info: Streaming services startup Mar 25 23:27:41 katarynka volumio[21232]: info: Starting Streaming Daemon Mar 25 23:27:41 katarynka sudo[21609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 23:27:41 katarynka sudo[21609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 23:27:41 katarynka volumio[21232]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 23:27:41 katarynka sudo[21609]: pam_unix(sudo:session): session closed for user root Mar 25 23:27:41 katarynka volumio[21232]: info: Getting Spotify volume Mar 25 23:27:41 katarynka volumio[21232]: info: Initializing connection to go-librespot Websocket Mar 25 23:27:41 katarynka volumio[21232]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 23:27:41 katarynka volumio[21232]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 23:27:41 katarynka volumio[21232]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 23:27:41 katarynka volumio[21232]: errno: -111, Mar 25 23:27:41 katarynka volumio[21232]: code: 'ECONNREFUSED', Mar 25 23:27:41 katarynka volumio[21232]: syscall: 'connect', Mar 25 23:27:41 katarynka volumio[21232]: address: '127.0.0.1', Mar 25 23:27:41 katarynka volumio[21232]: port: 9879, Mar 25 23:27:41 katarynka volumio[21232]: response: undefined Mar 25 23:27:41 katarynka volumio[21232]: } Mar 25 23:27:41 katarynka volumio[21232]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 23:27:43 katarynka sudo[21643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 23:26' Mar 25 23:27:43 katarynka sudo[21643]: 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"