Mar 25 07:45:01 katarynka volumio[12600]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:01 katarynka volumio[12600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:02 katarynka sudo[12927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:02 katarynka sudo[12927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:02 katarynka sudo[12929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:02 katarynka sudo[12929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:02 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 07:45:02 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 07:45:02 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:02 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:02 katarynka sudo[12929]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:02 katarynka sudo[12927]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:02 katarynka mpd_monitor.sh[12932]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 07:45:02 katarynka volumio[12600]: info: Successfully started MPD Monitor Mar 25 07:45:02 katarynka volumio[12600]: info: Successfully started MPD Monitor Mar 25 07:45:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 07:45:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:02 katarynka go-librespot[12936]: go-librespot daemon starting... Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="app state loaded" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+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 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+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 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=info msg="zeroconf server listening on port 35871" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="obtained new client token: AADwhO5J7/C/QfkejyRpce/j0Il3Xad3ps3+NGk9wiINR2TgiFWua8hbdnVn1cSHm16VjT/Nj7YZD2evDOHV8voVM+g3SjatidVVjoGUffjNffjye2pZFaa4Sj5gKQu+lhvr8jBYVkeOJQvqU738ahhcUwmwgRBGpoWUKQiSe8OhcuYO346rET374DyW72hzyg3jmodjnXnbXKgWplU8SQ/xt9oohQ8/Pgued4C/rKzVr1yHD/hzG3g/X4k=" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+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 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="completed challenge" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45: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 07:45:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:04 katarynka volumio[12600]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 07:45:04 katarynka volumio[12600]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:04 katarynka volumio[12600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 07:45:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:06 katarynka go-librespot[12944]: go-librespot daemon starting... Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="app state loaded" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=info msg="zeroconf server listening on port 35681" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="obtained new client token: AADe89YgBoslP2+//VQ+5l170T5Ue+HrTxKXGZAR9E+waTuKPmUYV/q85o+lSnOR1DdhP7Nv7Wdko9xyJzSozsOkg+q9YxEIawO9ODitd4on4zqzwNre5vsN64txpyTf7fQvo4EtrDrqKfH+i6oeyost4AU8rbJuVtfPvPz0BGUNE3t4MCayTiy3klJ1JX6yd6BS9HApj/JUZCH5UyE2/6D+u7ziSw8GyjDe0pNudCr6T1jHyNlLhg2iXSU=" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:07 katarynka volumio[12600]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="new websocket client" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="completed challenge" Mar 25 07:45:07 katarynka volumio[12600]: info: Connection to go-librespot Websocket established Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45: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 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 07:45:07 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:07 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 07:45:09 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:09 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:09 katarynka volumio[12600]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 07:45:09 katarynka volumio[12600]: info: MyVolumio login type: Token Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 07:45:10 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 07:45:10 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:10 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:10 katarynka go-librespot[12952]: go-librespot daemon starting... Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="app state loaded" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45: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 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45: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 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45: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 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=info msg="zeroconf server listening on port 46017" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="obtained new client token: AAC7P8s9T6AmLxiuFKZ1ayvUwipxXc7RDCTiTL5NI/cl26WJ+fFg1jM50VQWFzSbiRpgoduBo/4zul4K931HbMQX5MPC3+VS1XvLUh/wkcvWtRsLGVkEFhGbIYdZ+znOH/xQarLVqbHaIWn/fPcpgQa4RaNYz9qPypYx1pxv3B+ZkVcMExVZvUStbEMfCPfc2AauiBoxDgtsUGqwIPLkJiHVOuir0e9/G54GSYC+RCRQC5Fj/U3GiVyrLhs=" Mar 25 07:45:11 katarynka volumio[12600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 07:45:11 katarynka volumio[12600]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 07:45:11 katarynka volumio[12600]: info: Streaming services startup Mar 25 07:45:11 katarynka volumio[12600]: info: Starting Streaming Daemon Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:11 katarynka sudo[12961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 07:45:11 katarynka sudo[12961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:11 katarynka volumio[12600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="completed challenge" Mar 25 07:45:11 katarynka sudo[12961]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45: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 07:45:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:11 katarynka volumio[12600]: info: Getting Spotify volume Mar 25 07:45:11 katarynka volumio[12600]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:11 katarynka volumio[12600]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:11 katarynka volumio[12600]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 07:45:11 katarynka volumio[12600]: errno: -111, Mar 25 07:45:11 katarynka volumio[12600]: code: 'ECONNREFUSED', Mar 25 07:45:11 katarynka volumio[12600]: syscall: 'connect', Mar 25 07:45:11 katarynka volumio[12600]: address: '127.0.0.1', Mar 25 07:45:11 katarynka volumio[12600]: port: 9879, Mar 25 07:45:11 katarynka volumio[12600]: response: undefined Mar 25 07:45:11 katarynka volumio[12600]: } Mar 25 07:45:11 katarynka volumio[12600]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:13 katarynka sudo[12995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 07:44' Mar 25 07:45:13 katarynka sudo[12995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:13 katarynka sudo[12995]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:13 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 07:45:13 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 07:45:13 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:13 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 07:45:13 katarynka systemd[1]: volumio.service: Consumed 48.494s CPU time. Mar 25 07:45:14 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:45:14 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:45:14 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26104. Mar 25 07:45:14 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:45:14 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 07:45:14 katarynka systemd[1]: volumio.service: Consumed 48.494s CPU time. Mar 25 07:45:14 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 07:45:14 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:45:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 07:45:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:15 katarynka go-librespot[13022]: go-librespot daemon starting... Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="app state loaded" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+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 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+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 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=info msg="zeroconf server listening on port 39729" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="obtained new client token: AACOl5RhLL7Qp4j9O3Th89IFF9TvzKeP2r5NpOI2sQmYOg+DZjRt4PLx9IfIO166Kn+2tJ+2SNDD84JiSyIGES4CZ+Zjax1WajH8gKi1afMZ+NKGePgasgSytKznOu0GCTdtzCBTdnuvc8JtI2uwbw8tIRVFv6ysLto182y264jjncpar+ISr38oUHLa91zKftEE4JDo35l/LKvabbr/vhrL/3f/ewHRxhXaNjNPTSg7ZDNyMOzErCZ2dDI=" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:16 katarynka go-librespot[13023]: time="2026-03-25T07:45:16+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:16 katarynka go-librespot[13023]: time="2026-03-25T07:45:16+01:00" level=debug msg="completed challenge" Mar 25 07:45:16 katarynka go-librespot[13023]: time="2026-03-25T07:45: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 07:45:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:17 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:17 katarynka volumio[13007]: info: ----- Volumio3 ---- Mar 25 07:45:17 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:17 katarynka volumio[13007]: info: ----- System startup ---- Mar 25 07:45:17 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:18 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:18] [connect] Successful connection Mar 25 07:45:19 katarynka volumio[13007]: info: MYVOLUMIO Environment detected Mar 25 07:45:19 katarynka volumio[13007]: info: Plugin folders cleanup Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning into folder /volumio/app/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category audio_interface Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category miscellanea Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category music_service Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category plugins.json Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category system_controller Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category user_interface Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning into folder /data/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category music_service Mar 25 07:45:19 katarynka volumio[13007]: info: Plugin folders cleanup completed Mar 25 07:45:19 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:19 katarynka volumio[13007]: info: ----- Core plugins startup ---- Mar 25 07:45:19 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Adding plugin upnp to MyMusic Plugins Mar 25 07:45:19 katarynka volumio[13007]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 07:45:19 katarynka volumio[13007]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugins from folder /data/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugin "system"... Mar 25 07:45:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 07:45:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugin "appearance"... Mar 25 07:45:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:19 katarynka go-librespot[13040]: go-librespot daemon starting... Mar 25 07:45:19 katarynka go-librespot[13044]: time="2026-03-25T07:45:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:19 katarynka go-librespot[13044]: time="2026-03-25T07:45:19+01:00" level=debug msg="app state loaded" Mar 25 07:45:19 katarynka go-librespot[13044]: time="2026-03-25T07:45:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=info msg="zeroconf server listening on port 37713" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="obtained new client token: AACU/F+7X5fwOSSRNk6E7vxINZXyPqqXfovg22v4vxzNdloQLxYG/jd3MDtOfdl8t9NPXNU4kcaWUet70iNj7fLLCGg9B/nl59cUAMveTBM5ztl+KUzalSnGE7AO3Xe4ezY9HtdAmYuRWU7T3TEE8tAT8GWLVwJ4ySA/OQVbijFEdKv8t7KVDfK2xWBP62kNaJVRT1p+9egqUtb1gGQrSGYvCOG603cbHs5uxJW8D1EMazbj5xS4fkgHJuc=" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="completed challenge" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45: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 07:45:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:21 katarynka volumio[13007]: info: Loading plugin "network"... Mar 25 07:45:21 katarynka volumio[13007]: info: Refreshing Cached IP Addresses Mar 25 07:45:21 katarynka sudo[13052]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:45:21 katarynka sudo[13052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:21 katarynka sudo[13052]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:21 katarynka volumio[13007]: info: Loading plugin "services"... Mar 25 07:45:21 katarynka sudo[13054]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:45:21 katarynka sudo[13054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:21 katarynka volumio[13007]: info: Loading plugin "alsa_controller"... Mar 25 07:45:21 katarynka sudo[13054]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:21 katarynka sudo[13062]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 07:45:21 katarynka sudo[13062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:22 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "wizard"... Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "networkfs"... Mar 25 07:45:22 katarynka volumio[13007]: info: Starting Udev Watcher for removable devices Mar 25 07:45:22 katarynka volumio[13007]: info: Ignoring mount for partition: boot Mar 25 07:45:22 katarynka volumio[13007]: info: Ignoring mount for partition: volumio Mar 25 07:45:22 katarynka volumio[13007]: info: Ignoring mount for partition: volumio_data Mar 25 07:45:22 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "volumio_command_line_client"... Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "upnp"... Mar 25 07:45:22 katarynka volumio[13007]: info: [1774421122255] Starting Upmpd Daemon Mar 25 07:45:22 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "my_music"... Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "mpd"... Mar 25 07:45:22 katarynka sudo[13062]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "upnp_browser"... Mar 25 07:45:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 07:45:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:23 katarynka go-librespot[13088]: go-librespot daemon starting... Mar 25 07:45:23 katarynka go-librespot[13089]: time="2026-03-25T07:45:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:23 katarynka go-librespot[13089]: time="2026-03-25T07:45:23+01:00" level=debug msg="app state loaded" Mar 25 07:45:23 katarynka go-librespot[13089]: time="2026-03-25T07:45:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45: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 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45: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 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45: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 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=info msg="zeroconf server listening on port 39061" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="obtained new client token: AAA2sHpCjOpq37bkpGXQ0FgLdIQ7Plf/pwWFMaST7cpqyVRuzJW9sYB6q7GAJysUulTX9pXoWoWtnKLKjX8Ec4R22vksA4E9xKbjCrOOQ5WOzG0a6SF32uU/MF8nMNvGHypoo+rNhz0TIO+MayKPkmZ4+DP9knzFti4fSzWwF/wWrH77vV0I/425317ikbynoCZaUXGwkvj0Ri5uxOC4eyiDOTSN9uWh2HRfIZOKUORcLQnSQQxmteHkFTc=" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="completed challenge" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45: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 07:45:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:26 katarynka volumio[13007]: info: Starting UPNP Browser Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "alarm-clock"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "airplay_emulation"... Mar 25 07:45:26 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "last_100"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "webradio"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "i2s_dacs"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "volumiodiscovery"... Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka volumio[13007]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 07:45:26 katarynka volumio[13007]: info: Discovery: Started advertising with name: katarynka Mar 25 07:45:26 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "spop"... Mar 25 07:45:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 07:45:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:27 katarynka go-librespot[13098]: go-librespot daemon starting... Mar 25 07:45:27 katarynka go-librespot[13099]: time="2026-03-25T07:45:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:27 katarynka go-librespot[13099]: time="2026-03-25T07:45:27+01:00" level=debug msg="app state loaded" Mar 25 07:45:27 katarynka go-librespot[13099]: time="2026-03-25T07:45:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+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 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+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 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=info msg="zeroconf server listening on port 42485" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=debug msg="obtained new client token: AACdyHQMIH5FTNXupMS7zEOBtoIIM/Vd5ej2uvFHd6lTErCQpzXmJ6I9Ieq5ogFVaO3t/Z2jLaimh0V/dbruSv9mEWSXheuYHNLGwPzBpuutUZn5tUBSKAOWTqrGVtDJZ9djPSNp3LiAAmtftLgv2Xvfv4kIkAcRkPwfHj98qmGwWsRttFlDXnsGw1uv454SYXMIe97siwKXPHAqyl8lX63198O0dt5THpgi09xscf3OkbP+X061L3nZqg4=" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.100.107:38046->34.158.1.133:4070: read: connection reset by peer" Mar 25 07:45:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:28 katarynka volumio[13007]: info: Loading plugin "outputs"... Mar 25 07:45:28 katarynka volumio[13007]: info: Loading plugin "albumart"... Mar 25 07:45:28 katarynka volumio[13007]: info: Plugin example_plugin is not enabled Mar 25 07:45:28 katarynka volumio[13007]: info: Loading plugin "inputs"... Mar 25 07:45:29 katarynka volumio[13007]: info: Loading plugin "updater_comm"... Mar 25 07:45:29 katarynka volumio[13007]: info: Plugin mpdemulation is not enabled Mar 25 07:45:29 katarynka volumio[13007]: info: Loading plugin "rest_api"... Mar 25 07:45:29 katarynka volumio[13007]: info: Loading plugin "websocket"... Mar 25 07:45:29 katarynka volumio[13007]: info: Starting Socket.io Server version 1.7.4 Mar 25 07:45:29 katarynka volumio[13007]: info: Loading i18n strings for locale pl Mar 25 07:45:29 katarynka volumio[13007]: Updating browse sources language Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::initPlayerControls Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: Express server listening on port 3000 Mar 25 07:45:29 katarynka volumio[13007]: [Metrics] WebUI: 12s 683.44ms Mar 25 07:45:29 katarynka volumio[13007]: info: CoreStateMachine::resetVolumioState Mar 25 07:45:29 katarynka volumio[13007]: info: CoreStateMachine::getcurrentVolume Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:45:29 katarynka volumio[13007]: info: Cannot read play queue from file Mar 25 07:45:29 katarynka volumio[13007]: info: Volumio Network Manager: Network status updated: 2 Mar 25 07:45:30 katarynka volumio[13106]: Forking 3 albumart workers Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: Setting Device type: Raspberry PI Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::setRepeat null single undefined Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::setRandom null Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:30 katarynka volumio[13007]: info: Completed loading Core Plugins Mar 25 07:45:30 katarynka volumio[13007]: info: Preparing to generate the ALSA configuration file Mar 25 07:45:30 katarynka volumio[13007]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::updateTrackBlock Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrackBlock Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:45:30 katarynka volumio[13007]: info: Asound.conf file unchanged, so no further update is needed Mar 25 07:45:30 katarynka volumio[13007]: info: Output device has changed, restarting MPD Mar 25 07:45:30 katarynka volumio[13007]: info: Output device has changed, restarting Shairport Sync Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:30 katarynka sudo[13161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:45:30 katarynka sudo[13161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka sudo[13161]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:30 katarynka sudo[13163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:45:30 katarynka sudo[13163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka volumio[13007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:45:30 katarynka volumio[13007]: info: ___________ START PLUGINS ___________ Mar 25 07:45:30 katarynka volumio[13007]: info: ControllerMpd::onStart: Initializing MPD Mar 25 07:45:30 katarynka volumio[13007]: info: Creating MPD Configuration file Mar 25 07:45:30 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:45:30 katarynka volumio[13007]: info: [1774421130790] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:30 katarynka sudo[13173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:45:30 katarynka sudo[13173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:45:30 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:45:30 katarynka systemd[1]: mpd.service: Consumed 7.731s CPU time. Mar 25 07:45:30 katarynka volumio[13007]: info: UPNP Browser: Client initialized successfully Mar 25 07:45:30 katarynka sudo[13171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:45:30 katarynka sudo[13171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:45:30 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:45:30 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:45:30 katarynka sudo[13171]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:31 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:45:31 katarynka volumio[13007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:31 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:31 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:45:31 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:45:31 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:45:31 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:45:31 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:45:31 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:45:31 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:45:31 katarynka volumio[13007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:45:31 katarynka volumio[13007]: info: [1774421131219] CoreMusicLibrary::Adding element Last_100 Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:45:31 katarynka volumio[13007]: info: [1774421131239] CoreMusicLibrary::Adding element Webradio Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:45:31 katarynka volumio[13007]: info: Initializing BBC Radios Mar 25 07:45:31 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:31] [connect] Successful connection Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:31 katarynka volumio[13007]: info: Creating Spotify config file Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:31 katarynka sudo[13189]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 07:45:31 katarynka sudo[13189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 07:45:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 07:45:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:31 katarynka sudo[13189]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:31 katarynka go-librespot[13204]: go-librespot daemon starting... Mar 25 07:45:31 katarynka go-librespot[13205]: time="2026-03-25T07:45:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:32 katarynka go-librespot[13205]: time="2026-03-25T07:45:32+01:00" level=info msg="zeroconf server listening on port 44251" Mar 25 07:45:32 katarynka volumio[13007]: info: Volumio Calling Home Mar 25 07:45:33 katarynka volumio[13007]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:45:33 katarynka volumio[13007]: info: Discovery: Found device katarynka Mar 25 07:45:33 katarynka sudo[13231]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:45:33 katarynka sudo[13231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:33 katarynka volumio[13007]: info: CoreCommandRouter::volumioGetState Mar 25 07:45:33 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:33 katarynka sudo[13233]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:45:33 katarynka sudo[13233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:34 katarynka sudo[13233]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:34 katarynka sudo[13231]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:34 katarynka volumio[13007]: info: MPD Permissions set Mar 25 07:45:34 katarynka volumio[13007]: info: MPD Permissions set Mar 25 07:45:34 katarynka volumio[13007]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:45:34 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:34 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:34 katarynka volumio[13126]: Starting albumart workers Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:34 katarynka volumio[13007]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:45:34 katarynka volumio[13007]: info: Discovery: Found device katarynka Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::volumioGetState Mar 25 07:45:34 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:34 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774421131 101 Mar 25 07:45:34 katarynka volumio[13128]: Starting albumart workers Mar 25 07:45:34 katarynka volumio[13007]: 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 07:45:34 katarynka volumio[13123]: Starting albumart workers Mar 25 07:45:34 katarynka volumio[13007]: info: Volumio called home Mar 25 07:45:34 katarynka volumio[13007]: info: Spotify config file written Mar 25 07:45:34 katarynka sudo[13237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 07:45:34 katarynka sudo[13237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:34 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 07:45:34 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 07:45:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:34 katarynka volumio[13007]: 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 07:45:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:34 katarynka go-librespot[13239]: go-librespot daemon starting... Mar 25 07:45:34 katarynka sudo[13237]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka go-librespot[13240]: time="2026-03-25T07:45:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:34 katarynka go-librespot[13240]: time="2026-03-25T07:45:34+01:00" level=debug msg="app state loaded" Mar 25 07:45:34 katarynka go-librespot[13240]: time="2026-03-25T07:45:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: No need to fix Spotify hosts Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+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 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+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 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=info msg="zeroconf server listening on port 40703" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="obtained new client token: AABBbbH5/n3ovpqWQ573V0VVMDAnVWja9+95veq10L9v37ENoCfQWHYKOvsXzJT+30Q0TaYQHkygyiKjovGzcTqkWA7+WS67wg35J96eNFc+xTpJ3yOkONHmhIGzBoSpMrkxsz3XfHGSr0FqQQtKaA+Fw7K+tEkLlzlc81aagGQ0IlDSfYm6S7yYhw5n6qFNGYNc+qAqg2rsovcwJP47phLBsp+DClAXsX/Hl6Q0+sDD+M3ztFIGeY7sY/A=" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="completed challenge" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:35 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:35 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:36 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:36 katarynka sudo[13264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:45:36 katarynka sudo[13264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka sudo[13268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:45:36 katarynka sudo[13268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka sudo[13266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:45:36 katarynka sudo[13266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka sudo[13270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 07:45:36 katarynka sudo[13270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 07:45:36 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 07:45:36 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:45:36 katarynka systemd[1]: shairport-sync.service: Consumed 2.309s CPU time. Mar 25 07:45:36 katarynka sudo[13270]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka volumio[13007]: info: Upmpdcli Daemon Started Mar 25 07:45:36 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:45:36 katarynka sudo[13264]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka sudo[13266]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka volumio[13007]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 07:45:36 katarynka volumio[13007]: info: CoreCommandRouter::volumioGetState Mar 25 07:45:36 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:36 katarynka sudo[13268]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka volumio[13007]: info: Shairport-Sync Started Mar 25 07:45:36 katarynka volumio[13007]: Error adding Membership: Error: addMembership EINVAL Mar 25 07:45:36 katarynka volumio[13007]: info: Shairport-Sync Started Mar 25 07:45:36 katarynka volumio[13007]: info: Shairport-Sync Started Mar 25 07:45:38 katarynka volumio[13007]: info: go-librespot daemon successfully initialized Mar 25 07:45:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 07:45:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:39 katarynka go-librespot[13303]: go-librespot daemon starting... Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=debug msg="app state loaded" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:39 katarynka mpd[13206]: 2026-03-25T07:45:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 07:45:39 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 07:45:39 katarynka sudo[13163]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:39 katarynka sudo[13173]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:39 katarynka volumio[13007]: info: Completed starting Core Plugins Mar 25 07:45:39 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:39 katarynka volumio[13007]: info: ----- MyVolumio plugins startup ---- Mar 25 07:45:39 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:39 katarynka volumio[13007]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 07:45:39 katarynka volumio[13007]: error: MPD error: The expression evaluated to a falsy value: Mar 25 07:45:39 katarynka volumio[13007]: assert.ok(self.idling) Mar 25 07:45:39 katarynka volumio[13007]: error: The expression evaluated to a falsy value: Mar 25 07:45:39 katarynka volumio[13007]: assert.ok(self.idling) Mar 25 07:45:39 katarynka volumio[13007]: info: MPD running with PID13206 Mar 25 07:45:39 katarynka volumio[13007]: ,establishing connection Mar 25 07:45:39 katarynka volumio[13007]: error: updateQueue error: null Mar 25 07:45:39 katarynka volumio[13007]: error: updateQueue error: null Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+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 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+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 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=info msg="zeroconf server listening on port 41501" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=debug msg="obtained new client token: AAC25WWNESKbR1LGVd/0KCRsWrUPD+VBYFmAUmxHnue/1njuaQa+7/m3bP7s4a80ro6dxVV7HwlCXQL5Ee+7pq+NnVQ6PKKwF3eom1AxGQT1lOtNGNNwroLmQkDo1/D5Bvq0pSScG8C0P6bfScx2Uobafs6OVKo9tpA53akYY3UcunZ6A76qfmjb429WjT/I/7yuVVsXav7EnYBTMZfm4vw+5Zj2NXClJBV/r7widmvCgaiR35jtthfzIsw=" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:40 katarynka go-librespot[13304]: time="2026-03-25T07:45:40+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:40 katarynka go-librespot[13304]: time="2026-03-25T07:45:40+01:00" level=debug msg="completed challenge" Mar 25 07:45:40 katarynka go-librespot[13304]: time="2026-03-25T07:45:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:41 katarynka volumio[13007]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:41 katarynka volumio[13007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:42 katarynka sudo[13331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:42 katarynka sudo[13331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:42 katarynka sudo[13333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:42 katarynka sudo[13333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:42 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 07:45:42 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 07:45:42 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:42 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:42 katarynka sudo[13331]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:42 katarynka sudo[13333]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:42 katarynka mpd_monitor.sh[13336]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 07:45:42 katarynka volumio[13007]: info: Successfully started MPD Monitor Mar 25 07:45:42 katarynka volumio[13007]: info: Successfully started MPD Monitor Mar 25 07:45:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 07:45:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:43 katarynka go-librespot[13340]: go-librespot daemon starting... Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="app state loaded" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=info msg="zeroconf server listening on port 37019" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="obtained new client token: AABaMKmQBpBxK9w397/keO4MlgBj0vSoUFmJ9zERiPeDKtdsQBaeqw9dn7MybOqQZ+iYQ4nUnAFWAw1gB6ebwu5eO8AFYTDySNwNX6Kp6BKgXvYomNkMkLES2JAe95AcbG4LOHE3Ek7Ml/jN1jCmklG1oOpjCez53VA48xva5vdgOWYUcI5BjZETPcda5MZYFO2qLR7ajxl4mjBNeBo4XgDutPRdqI8itBBC767lZlTkq5+iybuAgLhBU5M=" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="completed challenge" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:44 katarynka volumio[13007]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 07:45:44 katarynka volumio[13007]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:44 katarynka volumio[13007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 07:45:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:47 katarynka go-librespot[13348]: go-librespot daemon starting... Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="app state loaded" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45: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-gae2.spotify.com:80]" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+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 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+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 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=info msg="zeroconf server listening on port 37285" Mar 25 07:45:47 katarynka volumio[13007]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="new websocket client" Mar 25 07:45:47 katarynka volumio[13007]: info: Connection to go-librespot Websocket established Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="obtained new client token: AACh4vlhcHuBb4obXEQLnvEo+s1JeICmsR5uqqVOahFVfy/6xCU0MAiWovLP1mBZmGSyY5axSRNVrZYIRupYy+Sw1k3x4Y0hbBU8TG/d1+xQfCTpf/f3t+Hp4LwusmRYgUQB9U3HqHX7XOdlUUMwQMhOI/t0OjW67gmYck3bppmspzERmtu4aoS1kfiVGZn6t9fLGhSYxF0PUcelDyhovYM8zjcjDCPmaMT9PjbdRty84C9N45L5HynqGdA=" Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="completed challenge" Mar 25 07:45:48 katarynka go-librespot[13349]: time="2026-03-25T07:45: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 07:45:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:49 katarynka volumio[13007]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 07:45:49 katarynka volumio[13007]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 07:45:49 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:49 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:49 katarynka volumio[13007]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 07:45:49 katarynka volumio[13007]: info: MyVolumio login type: Token Mar 25 07:45:50 katarynka volumio[13007]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 07:45:50 katarynka volumio[13007]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 07:45:51 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 07:45:51 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:51 katarynka go-librespot[13357]: go-librespot daemon starting... Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=debug msg="app state loaded" Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+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 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+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 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=info msg="zeroconf server listening on port 45929" Mar 25 07:45:51 katarynka volumio[13007]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 07:45:51 katarynka volumio[13007]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 07:45:51 katarynka volumio[13007]: info: Streaming services startup Mar 25 07:45:51 katarynka volumio[13007]: info: Starting Streaming Daemon Mar 25 07:45:51 katarynka sudo[13366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=debug msg="obtained new client token: AABWG/tT7R7Ms0mWvp6HtAFBheNQQAqcQ6F1iYXEQKgwigmL2lW02HphD8zf8SPvDj2bAtyuPl76d7FGASAyxWAH0XIC6X0pZEcwtHtnSwuy+vRpxFQhH1/25fF31eR0xNCS8URYhQqyFlPOElcAQbMYHba/ocrPSeMZea0YFjNmblTze6CF97SP/RG2IfUVkYZr32hQlj+RuJE6q5rXxGY0om4HW6Xo4Kqp0GVNDgEn3I8H712cYvf49Ss=" Mar 25 07:45:51 katarynka sudo[13366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:51 katarynka volumio[13007]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:51 katarynka sudo[13366]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:52 katarynka go-librespot[13358]: time="2026-03-25T07:45:52+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:52 katarynka go-librespot[13358]: time="2026-03-25T07:45:52+01:00" level=debug msg="completed challenge" Mar 25 07:45:52 katarynka volumio[13007]: info: Getting Spotify volume Mar 25 07:45:52 katarynka go-librespot[13358]: time="2026-03-25T07:45: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 07:45:52 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:52 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:52 katarynka volumio[13007]: info: Connection to go-librespot Websocket closed Mar 25 07:45:52 katarynka volumio[13007]: error: Cannot start Volumio Streaming Daemon Mar 25 07:45:52 katarynka volumio[13007]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 07:45:52 katarynka volumio[13007]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 07:45:52 katarynka volumio[13007]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:52 katarynka volumio[13007]: Error: socket hang up Mar 25 07:45:52 katarynka volumio[13007]: at connResetException (node:internal/errors:720:14) Mar 25 07:45:52 katarynka volumio[13007]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 07:45:52 katarynka volumio[13007]: at Socket.emit (node:events:526:35) Mar 25 07:45:52 katarynka volumio[13007]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 07:45:52 katarynka volumio[13007]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 07:45:52 katarynka volumio[13007]: code: 'ECONNRESET', Mar 25 07:45:52 katarynka volumio[13007]: response: undefined Mar 25 07:45:52 katarynka volumio[13007]: } Mar 25 07:45:52 katarynka volumio[13007]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:53 katarynka sudo[13401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 07:44' Mar 25 07:45:53 katarynka sudo[13401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:54 katarynka sudo[13401]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:54 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:54] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 07:45:54 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:54] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 07:45:54 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:54 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 07:45:54 katarynka systemd[1]: volumio.service: Consumed 49.351s CPU time. Mar 25 07:45:54 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:45:54 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:45:54 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26105. Mar 25 07:45:54 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:45:54 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 07:45:54 katarynka systemd[1]: volumio.service: Consumed 49.351s CPU time. Mar 25 07:45:54 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 07:45:54 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:45:55 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 07:45:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:55 katarynka go-librespot[13431]: go-librespot daemon starting... Mar 25 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+01:00" level=debug msg="app state loaded" Mar 25 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45: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-gew1.spotify.com:80]" Mar 25 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+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 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+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 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+01:00" level=info msg="zeroconf server listening on port 41385" Mar 25 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+01:00" level=debug msg="obtained new client token: AAAwkDJYaCa25ZH9SzQE65oenW0QcFhZtszWZpa8cEht1ye5/yk/LPBTCWpvzKfA2or6/ho98OPNOaztkOyoL1HQrSAkl+jpBTjpQHpSqeCJRw7Y4jkklNaEiKNRVirI82sUxBmRjmjLlIntNrBWTy9tHxulC9u0OB29INAojf7Dgz009Aida38hejGgG1EL8oT5CVbZWUg2mtIRCb73D0AE/Lu/SZV2iln0F+JmrXKxZOcXg7Uie5IFhAI=" Mar 25 07:45:55 katarynka go-librespot[13432]: time="2026-03-25T07:45:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:56 katarynka go-librespot[13432]: time="2026-03-25T07:45:56+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:56 katarynka go-librespot[13432]: time="2026-03-25T07:45:56+01:00" level=debug msg="completed challenge" Mar 25 07:45:56 katarynka go-librespot[13432]: time="2026-03-25T07:45: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 07:45:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:56 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:58 katarynka volumio[13416]: info: ------------------------------------------- Mar 25 07:45:58 katarynka volumio[13416]: info: ----- Volumio3 ---- Mar 25 07:45:58 katarynka volumio[13416]: info: ------------------------------------------- Mar 25 07:45:58 katarynka volumio[13416]: info: ----- System startup ---- Mar 25 07:45:58 katarynka volumio[13416]: info: ------------------------------------------- Mar 25 07:45:59 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 07:45:59 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:59 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:59 katarynka go-librespot[13445]: go-librespot daemon starting... Mar 25 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+01:00" level=debug msg="app state loaded" Mar 25 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:59 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:59] [connect] Successful connection Mar 25 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+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 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+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 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+01:00" level=info msg="zeroconf server listening on port 33911" Mar 25 07:45:59 katarynka go-librespot[13446]: time="2026-03-25T07:45:59+01:00" level=debug msg="obtained new client token: AABmH82eu9WV/I4h6xwtvfUUoApi5JBvb/1hU39s4bn5Co/tjfwwcsr8I897ohV/NVuY/a6lGPIsUOKJTvCYWtZU+d7Wu/NCEsAZ5HLr55AQdcuXPfWBaQ0USxwZOedK2vNvHzZ7meqDnc4FCWTqRz1N9g4TV72KbdH7A7xoaHl5377CvnG/DTqRfO9JodAksBVKzb1GZK1O5tuDdPKD464DO1KAJ+c7+NGXyVyvksm9qc7PnJKGsQy9pGE=" Mar 25 07:46:00 katarynka go-librespot[13446]: time="2026-03-25T07:46:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:00 katarynka go-librespot[13446]: time="2026-03-25T07:46:00+01:00" level=debug msg="completed keyexchange" Mar 25 07:46:00 katarynka go-librespot[13446]: time="2026-03-25T07:46:00+01:00" level=debug msg="completed challenge" Mar 25 07:46:00 katarynka volumio[13416]: info: MYVOLUMIO Environment detected Mar 25 07:46:00 katarynka go-librespot[13446]: time="2026-03-25T07:46:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:46:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:00 katarynka volumio[13416]: info: Plugin folders cleanup Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning into folder /volumio/app/plugins/ Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning category audio_interface Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning category miscellanea Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning category music_service Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning category plugins.json Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning category system_controller Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning category user_interface Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning into folder /data/plugins/ Mar 25 07:46:00 katarynka volumio[13416]: info: Scanning category music_service Mar 25 07:46:00 katarynka volumio[13416]: info: Plugin folders cleanup completed Mar 25 07:46:00 katarynka volumio[13416]: info: ------------------------------------------- Mar 25 07:46:00 katarynka volumio[13416]: info: ----- Core plugins startup ---- Mar 25 07:46:00 katarynka volumio[13416]: info: ------------------------------------------- Mar 25 07:46:00 katarynka volumio[13416]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 07:46:00 katarynka volumio[13416]: info: Adding plugin upnp to MyMusic Plugins Mar 25 07:46:00 katarynka volumio[13416]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 07:46:00 katarynka volumio[13416]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 07:46:00 katarynka volumio[13416]: info: Loading plugins from folder /data/plugins/ Mar 25 07:46:00 katarynka volumio[13416]: info: Loading plugin "system"... Mar 25 07:46:00 katarynka volumio[13416]: info: Loading plugin "appearance"... Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "network"... Mar 25 07:46:02 katarynka volumio[13416]: info: Refreshing Cached IP Addresses Mar 25 07:46:02 katarynka sudo[13460]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:46:02 katarynka sudo[13460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:02 katarynka sudo[13462]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:46:02 katarynka sudo[13462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:02 katarynka sudo[13460]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:02 katarynka sudo[13462]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "services"... Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "alsa_controller"... Mar 25 07:46:02 katarynka sudo[13473]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 07:46:02 katarynka sudo[13473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:02 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "wizard"... Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "networkfs"... Mar 25 07:46:02 katarynka volumio[13416]: info: Starting Udev Watcher for removable devices Mar 25 07:46:02 katarynka volumio[13416]: info: Ignoring mount for partition: boot Mar 25 07:46:02 katarynka volumio[13416]: info: Ignoring mount for partition: volumio Mar 25 07:46:02 katarynka volumio[13416]: info: Ignoring mount for partition: volumio_data Mar 25 07:46:02 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "volumio_command_line_client"... Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "upnp"... Mar 25 07:46:02 katarynka volumio[13416]: info: [1774421162836] Starting Upmpd Daemon Mar 25 07:46:02 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "my_music"... Mar 25 07:46:02 katarynka volumio[13416]: info: Loading plugin "mpd"... Mar 25 07:46:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 07:46:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:03 katarynka sudo[13473]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:03 katarynka go-librespot[13496]: go-librespot daemon starting... Mar 25 07:46:03 katarynka go-librespot[13497]: time="2026-03-25T07:46:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:03 katarynka go-librespot[13497]: time="2026-03-25T07:46:03+01:00" level=debug msg="app state loaded" Mar 25 07:46:03 katarynka go-librespot[13497]: time="2026-03-25T07:46:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:46:03 katarynka volumio[13416]: info: Loading plugin "upnp_browser"... Mar 25 07:46:03 katarynka go-librespot[13497]: time="2026-03-25T07:46:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:46:03 katarynka go-librespot[13497]: time="2026-03-25T07:46:03+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 07:46:03 katarynka go-librespot[13497]: time="2026-03-25T07:46:03+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 07:46:03 katarynka go-librespot[13497]: time="2026-03-25T07:46:03+01:00" level=info msg="zeroconf server listening on port 33709" Mar 25 07:46:04 katarynka go-librespot[13497]: time="2026-03-25T07:46:04+01:00" level=debug msg="obtained new client token: AAA0E3csZyhMxQFfP/1qpIUfp6/m1ZrWKdiHtarDrjcQejqPaR3OeJkueHqN+7bCXRd7XMsPJDAQmsz9puCFAe/LFdoWQrvOpw+bmNXkHA2L7FOW9Ud9Wrena101fY8d9YrZxz/8GlD8RBwjzxB9FxoBCx6RoWedWm9/Ge/xlb6xv/6JwTgcDlWDO9/GAUOqu2pmXXMW0YPGPGJtArPlOevxyO60D2suZn/A3Lur3HIESzR5mF1T59Dk" Mar 25 07:46:04 katarynka go-librespot[13497]: time="2026-03-25T07:46:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:04 katarynka go-librespot[13497]: time="2026-03-25T07:46:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 07:46:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:06 katarynka volumio[13416]: info: Starting UPNP Browser Mar 25 07:46:06 katarynka volumio[13416]: info: Loading plugin "alarm-clock"... Mar 25 07:46:06 katarynka volumio[13416]: info: Loading plugin "airplay_emulation"... Mar 25 07:46:06 katarynka volumio[13416]: info: Starting Shairport Sync Mar 25 07:46:06 katarynka volumio[13416]: info: Loading plugin "last_100"... Mar 25 07:46:06 katarynka volumio[13416]: info: Loading plugin "webradio"... Mar 25 07:46:07 katarynka volumio[13416]: info: Loading plugin "i2s_dacs"... Mar 25 07:46:07 katarynka volumio[13416]: info: Loading plugin "volumiodiscovery"... Mar 25 07:46:07 katarynka volumio[13416]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:46:07 katarynka volumio[13416]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:46:07 katarynka volumio[13416]: *** WARNING *** For more information see Mar 25 07:46:07 katarynka volumio[13416]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:46:07 katarynka volumio[13416]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:46:07 katarynka volumio[13416]: *** WARNING *** For more information see Mar 25 07:46:07 katarynka node[13416]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:46:07 katarynka node[13416]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:46:07 katarynka node[13416]: *** WARNING *** For more information see Mar 25 07:46:07 katarynka node[13416]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:46:07 katarynka node[13416]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:46:07 katarynka node[13416]: *** WARNING *** For more information see Mar 25 07:46:07 katarynka volumio[13416]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 07:46:07 katarynka volumio[13416]: info: Discovery: Started advertising with name: katarynka Mar 25 07:46:07 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:46:07 katarynka volumio[13416]: info: Loading plugin "spop"... Mar 25 07:46:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 07:46:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:07 katarynka go-librespot[13508]: go-librespot daemon starting... Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=debug msg="app state loaded" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+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 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+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 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+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 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=info msg="zeroconf server listening on port 43319" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=debug msg="obtained new client token: AADRHedO1gwEwDZwche+iy2b4o58F9M9HpDS6ogrWFyXpmp6Tax7tZf8n5AwutApfNhmUPfM9ogBgAF7GpLqWqu8Sz4TtlsSQm3UUdD6Jkuqq8Li2TSjnmHJ+dhwLw+oX9bDzUIH6dtxOAYqNLwXHjkiZwTxVzuiM/9Fph2UKkGUYgB9+3Cks7+ZgUWSOKVcEca5hDk2PuXh3k0Uz9Mc1TWRYx/ft9nwj88hzy9GI0fz1k+MldcXgmG2uGI=" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=debug msg="completed keyexchange" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=debug msg="completed challenge" Mar 25 07:46:08 katarynka go-librespot[13509]: time="2026-03-25T07:46:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:46:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:09 katarynka volumio[13416]: info: Loading plugin "outputs"... Mar 25 07:46:09 katarynka volumio[13416]: info: Loading plugin "albumart"... Mar 25 07:46:09 katarynka volumio[13416]: info: Plugin example_plugin is not enabled Mar 25 07:46:09 katarynka volumio[13416]: info: Loading plugin "inputs"... Mar 25 07:46:09 katarynka volumio[13416]: info: Loading plugin "updater_comm"... Mar 25 07:46:09 katarynka volumio[13416]: info: Plugin mpdemulation is not enabled Mar 25 07:46:09 katarynka volumio[13416]: info: Loading plugin "rest_api"... Mar 25 07:46:09 katarynka volumio[13416]: info: Loading plugin "websocket"... Mar 25 07:46:09 katarynka volumio[13416]: info: Starting Socket.io Server version 1.7.4 Mar 25 07:46:09 katarynka volumio[13416]: info: Loading i18n strings for locale pl Mar 25 07:46:09 katarynka volumio[13416]: Updating browse sources language Mar 25 07:46:09 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::initPlayerControls Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: Express server listening on port 3000 Mar 25 07:46:10 katarynka volumio[13416]: [Metrics] WebUI: 12s 520.85ms Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::resetVolumioState Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::getcurrentVolume Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:46:10 katarynka volumio[13416]: info: Cannot read play queue from file Mar 25 07:46:10 katarynka volumio[13416]: info: Volumio Network Manager: Network status updated: 2 Mar 25 07:46:10 katarynka volumio[13517]: Forking 3 albumart workers Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::pushState Mar 25 07:46:10 katarynka volumio[13416]: info: CorePlayQueue::getTrack 0 Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::volumioPushState Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::updateTrackBlock Mar 25 07:46:10 katarynka volumio[13416]: info: CorePlayQueue::getTrackBlock Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::setRepeat null single undefined Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::pushState Mar 25 07:46:10 katarynka volumio[13416]: info: CorePlayQueue::getTrack 0 Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::volumioPushState Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::setRandom null Mar 25 07:46:10 katarynka volumio[13416]: info: CoreStateMachine::pushState Mar 25 07:46:10 katarynka volumio[13416]: info: CorePlayQueue::getTrack 0 Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::volumioPushState Mar 25 07:46:10 katarynka volumio[13416]: info: Setting Device type: Raspberry PI Mar 25 07:46:10 katarynka volumio[13416]: info: Completed loading Core Plugins Mar 25 07:46:10 katarynka volumio[13416]: info: Preparing to generate the ALSA configuration file Mar 25 07:46:10 katarynka volumio[13416]: info: Asound.conf file unchanged, so no further update is needed Mar 25 07:46:10 katarynka volumio[13416]: info: Output device has changed, restarting MPD Mar 25 07:46:10 katarynka volumio[13416]: info: Output device has changed, restarting Shairport Sync Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:10 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:11 katarynka sudo[13574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:46:11 katarynka sudo[13574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:11 katarynka sudo[13572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:46:11 katarynka sudo[13572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:11 katarynka sudo[13572]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:11 katarynka volumio[13416]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:46:11 katarynka volumio[13416]: info: ___________ START PLUGINS ___________ Mar 25 07:46:11 katarynka volumio[13416]: info: ControllerMpd::onStart: Initializing MPD Mar 25 07:46:11 katarynka volumio[13416]: info: Creating MPD Configuration file Mar 25 07:46:11 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:46:11 katarynka volumio[13416]: info: [1774421171207] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 07:46:11 katarynka sudo[13582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:46:11 katarynka sudo[13582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:46:11 katarynka sudo[13582]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:11 katarynka volumio[13416]: info: UPNP Browser: Client initialized successfully Mar 25 07:46:11 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:46:11 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:46:11 katarynka systemd[1]: mpd.service: Consumed 7.671s CPU time. Mar 25 07:46:11 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:46:11 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:46:11 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:46:11 katarynka sudo[13584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:46:11 katarynka sudo[13584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:11 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:46:11 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:46:11 katarynka volumio[13416]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:11 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:46:11 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:46:11 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:46:11 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:46:11 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:46:11 katarynka volumio[13416]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:46:11 katarynka volumio[13416]: info: [1774421171613] CoreMusicLibrary::Adding element Last_100 Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:46:11 katarynka volumio[13416]: info: [1774421171634] CoreMusicLibrary::Adding element Webradio Mar 25 07:46:11 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:46:11 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:46:11 katarynka volumio[13416]: info: Initializing BBC Radios Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 07:46:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:11 katarynka volumio[13416]: info: Creating Spotify config file Mar 25 07:46:11 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:12 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:12 katarynka go-librespot[13613]: go-librespot daemon starting... Mar 25 07:46:12 katarynka volumio-remote-updater[622]: [2026-03-25 07:46:12] [connect] Successful connection Mar 25 07:46:12 katarynka go-librespot[13614]: time="2026-03-25T07:46:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:12 katarynka sudo[13599]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 07:46:12 katarynka sudo[13599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 07:46:12 katarynka sudo[13599]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:12 katarynka go-librespot[13614]: time="2026-03-25T07:46:12+01:00" level=info msg="zeroconf server listening on port 33201" Mar 25 07:46:13 katarynka volumio[13416]: info: Volumio Calling Home Mar 25 07:46:14 katarynka volumio[13533]: Starting albumart workers Mar 25 07:46:14 katarynka volumio[13539]: Starting albumart workers Mar 25 07:46:14 katarynka volumio[13537]: Starting albumart workers Mar 25 07:46:14 katarynka volumio[13416]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:46:14 katarynka volumio[13416]: info: Discovery: Found device katarynka Mar 25 07:46:14 katarynka volumio[13416]: info: CoreCommandRouter::volumioGetState Mar 25 07:46:14 katarynka volumio[13416]: info: CorePlayQueue::getTrack 0 Mar 25 07:46:14 katarynka sudo[13643]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:46:14 katarynka sudo[13643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:14 katarynka sudo[13641]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:46:14 katarynka sudo[13641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:14 katarynka sudo[13643]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:14 katarynka sudo[13641]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:14 katarynka volumio[13416]: info: MPD Permissions set Mar 25 07:46:14 katarynka volumio[13416]: info: MPD Permissions set Mar 25 07:46:14 katarynka volumio[13416]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:46:14 katarynka volumio[13416]: info: CoreStateMachine::pushState Mar 25 07:46:14 katarynka volumio[13416]: info: CorePlayQueue::getTrack 0 Mar 25 07:46:14 katarynka volumio[13416]: info: CoreCommandRouter::volumioPushState Mar 25 07:46:14 katarynka volumio-remote-updater[622]: [2026-03-25 07:46:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774421172 101 Mar 25 07:46:14 katarynka volumio[13416]: 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 07:46:14 katarynka volumio[13416]: info: Spotify config file written Mar 25 07:46:14 katarynka volumio[13416]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:46:14 katarynka volumio[13416]: info: Discovery: Found device katarynka Mar 25 07:46:14 katarynka volumio[13416]: info: CoreCommandRouter::volumioGetState Mar 25 07:46:14 katarynka volumio[13416]: info: CorePlayQueue::getTrack 0 Mar 25 07:46:14 katarynka sudo[13647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 07:46:14 katarynka sudo[13647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:15 katarynka volumio[13416]: 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 07:46:15 katarynka volumio[13416]: info: Volumio called home Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 07:46:15 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 07:46:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:15 katarynka go-librespot[13654]: go-librespot daemon starting... Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:15 katarynka sudo[13647]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:15 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:46:15 katarynka volumio[13416]: info: No need to fix Spotify hosts Mar 25 07:46:15 katarynka go-librespot[13657]: time="2026-03-25T07:46:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:15 katarynka go-librespot[13657]: time="2026-03-25T07:46:15+01:00" level=debug msg="app state loaded" Mar 25 07:46:15 katarynka go-librespot[13657]: time="2026-03-25T07:46:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:46:15 katarynka volumio[13416]: info: Starting Shairport Sync Mar 25 07:46:15 katarynka volumio[13416]: info: Starting Shairport Sync Mar 25 07:46:15 katarynka volumio[13416]: info: Starting Shairport Sync Mar 25 07:46:15 katarynka go-librespot[13657]: time="2026-03-25T07:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:46:15 katarynka go-librespot[13657]: time="2026-03-25T07:46:15+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 07:46:15 katarynka go-librespot[13657]: time="2026-03-25T07:46:15+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 07:46:16 katarynka go-librespot[13657]: time="2026-03-25T07:46:16+01:00" level=info msg="zeroconf server listening on port 34161" Mar 25 07:46:16 katarynka sudo[13668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:46:16 katarynka sudo[13668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:16 katarynka go-librespot[13657]: time="2026-03-25T07:46:16+01:00" level=debug msg="obtained new client token: AADPGc8alY0szv6jfazczRDWuOmUxCRlTuMtNcx67ExRos0NhE9So7RLdo69v4fwW2AL0SGHIY6xdxy34iRTdzECl26BoHWmrd5uhg0MiHrFC9HZyS3lQQxioDhtqs1jktBro2U3rbhD2Vr9tlIq33ykfHT33lPHj+pYzS8HyUcKtd7jNQTDqhV+Go90O/QoIydn8Ib2JOrNlphi0XFZEkuJfDUazIGZoYbWIW3ekyi6kGNgaAKxKPtk" Mar 25 07:46:16 katarynka sudo[13670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:46:16 katarynka volumio[13416]: info: CoreCommandRouter::volumioGetState Mar 25 07:46:16 katarynka volumio[13416]: info: CorePlayQueue::getTrack 0 Mar 25 07:46:16 katarynka sudo[13670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:16 katarynka go-librespot[13657]: time="2026-03-25T07:46:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:16 katarynka sudo[13675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 07:46:16 katarynka sudo[13675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:16 katarynka sudo[13672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:46:16 katarynka sudo[13672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:16 katarynka go-librespot[13657]: time="2026-03-25T07:46:16+01:00" level=debug msg="completed keyexchange" Mar 25 07:46:16 katarynka go-librespot[13657]: time="2026-03-25T07:46:16+01:00" level=debug msg="completed challenge" Mar 25 07:46:16 katarynka go-librespot[13657]: time="2026-03-25T07:46: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 07:46:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:16 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 07:46:16 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 07:46:16 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:46:16 katarynka systemd[1]: shairport-sync.service: Consumed 2.365s CPU time. Mar 25 07:46:16 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:46:16 katarynka volumio[13416]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 07:46:16 katarynka sudo[13670]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:16 katarynka sudo[13672]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:16 katarynka sudo[13668]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:16 katarynka sudo[13675]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:17 katarynka volumio[13416]: info: Shairport-Sync Started Mar 25 07:46:17 katarynka volumio[13416]: Error adding Membership: Error: addMembership EINVAL Mar 25 07:46:17 katarynka volumio[13416]: info: Upmpdcli Daemon Started Mar 25 07:46:17 katarynka volumio[13416]: info: Shairport-Sync Started Mar 25 07:46:17 katarynka volumio[13416]: info: Shairport-Sync Started Mar 25 07:46:18 katarynka volumio[13416]: info: go-librespot daemon successfully initialized Mar 25 07:46:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 07:46:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:19 katarynka go-librespot[13713]: go-librespot daemon starting... Mar 25 07:46:19 katarynka go-librespot[13714]: time="2026-03-25T07:46:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:19 katarynka go-librespot[13714]: time="2026-03-25T07:46:19+01:00" level=debug msg="app state loaded" Mar 25 07:46:19 katarynka go-librespot[13714]: time="2026-03-25T07:46:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:46:19 katarynka mpd[13621]: 2026-03-25T07:46:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 07:46:19 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 07:46:19 katarynka sudo[13574]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:19 katarynka sudo[13584]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:19 katarynka volumio[13416]: info: Completed starting Core Plugins Mar 25 07:46:19 katarynka volumio[13416]: info: ------------------------------------------- Mar 25 07:46:19 katarynka volumio[13416]: info: ----- MyVolumio plugins startup ---- Mar 25 07:46:19 katarynka volumio[13416]: info: ------------------------------------------- Mar 25 07:46:19 katarynka volumio[13416]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 07:46:20 katarynka volumio[13416]: error: MPD error: The expression evaluated to a falsy value: Mar 25 07:46:20 katarynka volumio[13416]: assert.ok(self.idling) Mar 25 07:46:20 katarynka volumio[13416]: error: The expression evaluated to a falsy value: Mar 25 07:46:20 katarynka volumio[13416]: assert.ok(self.idling) Mar 25 07:46:20 katarynka volumio[13416]: info: MPD running with PID13621 Mar 25 07:46:20 katarynka volumio[13416]: ,establishing connection Mar 25 07:46:20 katarynka volumio[13416]: error: updateQueue error: null Mar 25 07:46:20 katarynka volumio[13416]: error: updateQueue error: null Mar 25 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+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 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+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 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+01:00" level=info msg="zeroconf server listening on port 38609" Mar 25 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+01:00" level=debug msg="obtained new client token: AABYCcpVaELa96le48dstsIhlKbHHMNOkzR2Sw28VRj+L90YWmlm0wKOjGG65WTmCDnCYlc5ADNNY+yO2rC6iSD3nEuFo0tbpgiAUwqljfoDC3ePiqaDC9iMbDvqXLxwg2hUn4TO3hMHSwrScueT53j7JCNN/Hi4Q1ILbpLA/s5W4qY4Y1R7esyUUTn5AlvMHkF5clmns0LwbVXxq5mC9HA2OMnP5n1DPYt/BtXD8M8HOY5I9zKVfZRSd8Y=" Mar 25 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+01:00" level=debug msg="completed keyexchange" Mar 25 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46:20+01:00" level=debug msg="completed challenge" Mar 25 07:46:20 katarynka go-librespot[13714]: time="2026-03-25T07:46: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 07:46:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:21 katarynka volumio[13416]: info: Initializing connection to go-librespot Websocket Mar 25 07:46:21 katarynka volumio[13416]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:46:22 katarynka sudo[13743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:46:22 katarynka sudo[13743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:23 katarynka sudo[13745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:46:23 katarynka sudo[13745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:23 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 07:46:23 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 07:46:23 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 07:46:23 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 07:46:23 katarynka sudo[13745]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:23 katarynka sudo[13743]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:23 katarynka mpd_monitor.sh[13748]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 07:46:23 katarynka volumio[13416]: info: Successfully started MPD Monitor Mar 25 07:46:23 katarynka volumio[13416]: info: Successfully started MPD Monitor Mar 25 07:46:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 07:46:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:23 katarynka go-librespot[13752]: go-librespot daemon starting... Mar 25 07:46:23 katarynka go-librespot[13753]: time="2026-03-25T07:46:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:23 katarynka go-librespot[13753]: time="2026-03-25T07:46:23+01:00" level=debug msg="app state loaded" Mar 25 07:46:23 katarynka go-librespot[13753]: time="2026-03-25T07:46:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46: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-gew1.spotify.com:80]" Mar 25 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46:24+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 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46:24+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 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46:24+01:00" level=info msg="zeroconf server listening on port 37199" Mar 25 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46:24+01:00" level=debug msg="obtained new client token: AABe/ad3aJ2w0ddCIpmvuUTJXjPRUx5Ar8euhD7vVwJsHEmwRv5iAbG/fsLF3PJXXtJwgPqlrLaEMwIg2Va6DT/Q8QvZ6XIST26MBIEkP7lvtnAxqZOLfnNLUxdSPQJtpyFbT1LdbJDhvTlOkcUsVG2sZbalVf3crZdSC1lApmrq5iFtJ70dhPly5atq8DhaB+IBUVJkJND6FmbhSAbVIu++7OdnbNb5hNmrzUTsGYMlzN+T3eoHMLnZLRA=" Mar 25 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46:24+01:00" level=debug msg="completed keyexchange" Mar 25 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46:24+01:00" level=debug msg="completed challenge" Mar 25 07:46:24 katarynka go-librespot[13753]: time="2026-03-25T07:46: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 07:46:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:24 katarynka volumio[13416]: info: Initializing connection to go-librespot Websocket Mar 25 07:46:24 katarynka volumio[13416]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:46:25 katarynka volumio[13416]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 07:46:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 07:46:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:27 katarynka go-librespot[13761]: go-librespot daemon starting... Mar 25 07:46:27 katarynka go-librespot[13762]: time="2026-03-25T07:46:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:27 katarynka go-librespot[13762]: time="2026-03-25T07:46:27+01:00" level=debug msg="app state loaded" Mar 25 07:46:27 katarynka go-librespot[13762]: time="2026-03-25T07:46:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:46:27 katarynka volumio[13416]: info: Initializing connection to go-librespot Websocket Mar 25 07:46:27 katarynka go-librespot[13762]: time="2026-03-25T07:46:27+01:00" level=debug msg="new websocket client" Mar 25 07:46:27 katarynka volumio[13416]: info: Connection to go-librespot Websocket established Mar 25 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46:28+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 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46:28+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 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46:28+01:00" level=info msg="zeroconf server listening on port 34711" Mar 25 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46:28+01:00" level=debug msg="obtained new client token: AADsMn6baYisvdUki/mFQv+GSBFwsjmosfR5yKKesexlRMaaLKOp5tI9IFp8FHjDYhGGXwhzO45vPcHngrNDyBY5CsicZ3ClNMhYQIs0HCEExePk6bNLQFLCLv2/AyMipWgad8qYs339qybM/mCs89dzESaX/7KpkjNkgdWuUGkIaM8DEB55QuTaDIrp2NOBR4KuSLqIMA03w/+KNREmVrOIChWLqcLUIpfNA1/bbypM8oJuHWuVj4p8a94=" Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 07:46:28 katarynka volumio[13416]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 07:46:28 katarynka volumio[13416]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 07:46:28 katarynka volumio[13416]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 07:46:28 katarynka volumio[13416]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 07:46:28 katarynka volumio[13416]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 07:46:28 katarynka volumio[13416]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 07:46:28 katarynka volumio[13416]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 07:46:28 katarynka volumio[13416]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46:28+01:00" level=debug msg="completed keyexchange" Mar 25 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46:28+01:00" level=debug msg="completed challenge" Mar 25 07:46:28 katarynka go-librespot[13762]: time="2026-03-25T07:46: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 07:46:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:30 katarynka volumio[13416]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 07:46:30 katarynka volumio[13416]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 07:46:30 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:30 katarynka volumio[13416]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:46:30 katarynka volumio[13416]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 07:46:30 katarynka volumio[13416]: info: MyVolumio login type: Token Mar 25 07:46:30 katarynka volumio[13416]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 07:46:30 katarynka volumio[13416]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 07:46:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 07:46:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:46:31 katarynka go-librespot[13770]: go-librespot daemon starting... Mar 25 07:46:31 katarynka go-librespot[13771]: time="2026-03-25T07:46:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:46:31 katarynka go-librespot[13771]: time="2026-03-25T07:46:31+01:00" level=debug msg="app state loaded" Mar 25 07:46:31 katarynka go-librespot[13771]: time="2026-03-25T07:46:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46: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-gew1.spotify.com:80]" Mar 25 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46:32+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 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46:32+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 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46:32+01:00" level=info msg="zeroconf server listening on port 38359" Mar 25 07:46:32 katarynka volumio[13416]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 07:46:32 katarynka volumio[13416]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 07:46:32 katarynka volumio[13416]: info: Streaming services startup Mar 25 07:46:32 katarynka volumio[13416]: info: Starting Streaming Daemon Mar 25 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46:32+01:00" level=debug msg="obtained new client token: AACqsMyq7TqZX3LsxnWuxy+VB1MVRcp1gO3v7LGLUgocO1xTYPjH8lGzBrbuqWQDYP7TNhltl66GX6yWo81v0YK8tMj0tlDHuV1HY8LmgVz7a2mB7OcbxChf50MT8pwcd/Y4q/EAi5hCocCSroAq5vzVYUQekg1S4XSMW0i0x5kpDxZ0c1v/DWB/OOHy703PAWATKYgkucpelqTd2KnsR/vb5iCX0Vkav4QBdwF0YjWDc0mpNJWIqb7V2tU=" Mar 25 07:46:32 katarynka sudo[13779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 07:46:32 katarynka sudo[13779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:46:32 katarynka volumio[13416]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:46:32 katarynka sudo[13779]: pam_unix(sudo:session): session closed for user root Mar 25 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46:32+01:00" level=debug msg="completed keyexchange" Mar 25 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46:32+01:00" level=debug msg="completed challenge" Mar 25 07:46:32 katarynka volumio[13416]: info: Getting Spotify volume Mar 25 07:46:32 katarynka go-librespot[13771]: time="2026-03-25T07:46: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 07:46:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:46:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:46:32 katarynka volumio[13416]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:46:32 katarynka volumio[13416]: Error: connect ECONNRESET 127.0.0.1:9879 Mar 25 07:46:32 katarynka volumio[13416]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 07:46:32 katarynka volumio[13416]: errno: -104, Mar 25 07:46:32 katarynka volumio[13416]: code: 'ECONNRESET', Mar 25 07:46:32 katarynka volumio[13416]: syscall: 'connect', Mar 25 07:46:32 katarynka volumio[13416]: address: '127.0.0.1', Mar 25 07:46:32 katarynka volumio[13416]: port: 9879, Mar 25 07:46:32 katarynka volumio[13416]: response: undefined Mar 25 07:46:32 katarynka volumio[13416]: } Mar 25 07:46:32 katarynka volumio[13416]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:46:34 katarynka sudo[13813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 07:45' Mar 25 07:46:34 katarynka sudo[13813]: 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"