Mar 25 19:03:02 katarynka volumio[6286]: info: Getting Spotify volume Mar 25 19:03:02 katarynka volumio[6286]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:03:02 katarynka volumio[6286]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:03:02 katarynka volumio[6286]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 19:03:02 katarynka volumio[6286]: errno: -111, Mar 25 19:03:02 katarynka volumio[6286]: code: 'ECONNREFUSED', Mar 25 19:03:02 katarynka volumio[6286]: syscall: 'connect', Mar 25 19:03:02 katarynka volumio[6286]: address: '127.0.0.1', Mar 25 19:03:02 katarynka volumio[6286]: port: 9879, Mar 25 19:03:02 katarynka volumio[6286]: response: undefined Mar 25 19:03:02 katarynka volumio[6286]: } Mar 25 19:03:02 katarynka volumio[6286]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:03:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 19:03:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:03 katarynka go-librespot[6811]: go-librespot daemon starting... Mar 25 19:03:03 katarynka systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=debug msg="app state loaded" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+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 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+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 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=info msg="zeroconf server listening on port 39437" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=debug msg="obtained new client token: AADbIT7IX4nC9+Ij/xGDJf4oWbVBeXAu6YtuLeSfhlef7GpcRWR5hFqQza5oEJ1w0/1v/F7SOYTyp+5d8G2o6GWmatgZjlo/qN6KrpAWYbUuTN4jJewVLJLE9Zs84afA4HL8bIMd/R00qB6IbD5oexAlahLF+Dj+9okLWOOg/YMyQIBUIk36HIFQnPjbS+HyEC0+nsWSJLEsEqSMgBC7ev7SMGIFRXizhnIX5R6hPSpUx/AAMoyrLc5TVZc=" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03:03+01:00" level=debug msg="completed challenge" Mar 25 19:03:03 katarynka go-librespot[6812]: time="2026-03-25T19:03: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 19:03:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:04 katarynka sudo[6837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 19:02' Mar 25 19:03:04 katarynka sudo[6837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:04 katarynka sudo[6837]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:04 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 19:03:04 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 19:03:04 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:04 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 19:03:04 katarynka systemd[1]: volumio.service: Consumed 53.210s CPU time. Mar 25 19:03:04 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:03:04 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 85. Mar 25 19:03:04 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:03:04 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 19:03:04 katarynka systemd[1]: volumio.service: Consumed 53.210s CPU time. Mar 25 19:03:04 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 19:03:05 katarynka systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 25 19:03:05 katarynka systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 25 19:03:05 katarynka systemd[1]: setdatetime-helper.service: Consumed 2.079s CPU time. Mar 25 19:03:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 19:03:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:07 katarynka go-librespot[6870]: go-librespot daemon starting... Mar 25 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03:07+01:00" level=debug msg="app state loaded" Mar 25 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03:07+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 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03:07+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 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03:07+01:00" level=info msg="zeroconf server listening on port 35965" Mar 25 19:03:07 katarynka go-librespot[6871]: time="2026-03-25T19:03:07+01:00" level=debug msg="obtained new client token: AADK0yz8MswgheoGe/tUg4nvCraD/GsmYodA5mhRlYY6RTv807oqCw+TYPCdzX2K+YGuGj35ShxsE7W/Iky1QZKUn5uYl0diRnjmYOJZgEpAUBoqFuB/a85Zs9WRbqOf1dMoMFZKwmmXP6PJwBgu9jgTeiXyadwlXmmzWZtAa98uvK64j4XruFliD2OOKNffbaoydQPAH4EE40rF59N7f2wS5Wbdi+oGOOkxZvHPemw5ErAbU5f7ooAaOEM=" Mar 25 19:03:08 katarynka go-librespot[6871]: time="2026-03-25T19:03:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:08 katarynka go-librespot[6871]: time="2026-03-25T19:03:08+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:08 katarynka go-librespot[6871]: time="2026-03-25T19:03:08+01:00" level=debug msg="completed challenge" Mar 25 19:03:08 katarynka go-librespot[6871]: time="2026-03-25T19:03: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 19:03:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:08 katarynka volumio[6856]: info: ------------------------------------------- Mar 25 19:03:08 katarynka volumio[6856]: info: ----- Volumio3 ---- Mar 25 19:03:08 katarynka volumio[6856]: info: ------------------------------------------- Mar 25 19:03:08 katarynka volumio[6856]: info: ----- System startup ---- Mar 25 19:03:08 katarynka volumio[6856]: info: ------------------------------------------- Mar 25 19:03:09 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:09] [connect] Successful connection Mar 25 19:03:10 katarynka volumio[6856]: info: MYVOLUMIO Environment detected Mar 25 19:03:10 katarynka volumio[6856]: info: Plugin folders cleanup Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning into folder /volumio/app/plugins/ Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning category audio_interface Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning category miscellanea Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning category music_service Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning category plugins.json Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning category system_controller Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning category user_interface Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning into folder /data/plugins/ Mar 25 19:03:10 katarynka volumio[6856]: info: Scanning category music_service Mar 25 19:03:10 katarynka volumio[6856]: info: Plugin folders cleanup completed Mar 25 19:03:10 katarynka volumio[6856]: info: ------------------------------------------- Mar 25 19:03:10 katarynka volumio[6856]: info: ----- Core plugins startup ---- Mar 25 19:03:10 katarynka volumio[6856]: info: ------------------------------------------- Mar 25 19:03:10 katarynka volumio[6856]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 19:03:10 katarynka volumio[6856]: info: Adding plugin upnp to MyMusic Plugins Mar 25 19:03:10 katarynka volumio[6856]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 19:03:10 katarynka volumio[6856]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 19:03:10 katarynka volumio[6856]: info: Loading plugins from folder /data/plugins/ Mar 25 19:03:10 katarynka volumio[6856]: info: Loading plugin "system"... Mar 25 19:03:10 katarynka volumio[6856]: info: Loading plugin "appearance"... Mar 25 19:03:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 19:03:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:11 katarynka go-librespot[6894]: go-librespot daemon starting... Mar 25 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03:11+01:00" level=debug msg="app state loaded" Mar 25 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03:11+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 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03:11+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 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03:11+01:00" level=info msg="zeroconf server listening on port 38711" Mar 25 19:03:11 katarynka go-librespot[6895]: time="2026-03-25T19:03:11+01:00" level=debug msg="obtained new client token: AAB/C2vlHuKBIRlGIa1UDYz5kN6YVAQIDSiRAbaC29a1Z14FjjB0WEMcqQX5Ib7x85DXt3Y3ZZ91Hzk910WaJ3Xixa9h4XjHW/hTzFhjy/XcySvvedpPGxqL313oIvyt6on8p5SKriwAxPg0u+S8es0mWid5eYDqE8bFx1iUi7PsvU6YPEQHE2/3PLWYLJu48/AIrK6ronfWMY4oR7l3L4RZexPjpvzG1KT1PIv3mMTpdIhcanRICz6dZHs=" Mar 25 19:03:12 katarynka go-librespot[6895]: time="2026-03-25T19:03:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:12 katarynka go-librespot[6895]: time="2026-03-25T19:03:12+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:12 katarynka go-librespot[6895]: time="2026-03-25T19:03:12+01:00" level=debug msg="completed challenge" Mar 25 19:03:12 katarynka go-librespot[6895]: time="2026-03-25T19:03:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:03:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "network"... Mar 25 19:03:12 katarynka volumio[6856]: info: Refreshing Cached IP Addresses Mar 25 19:03:12 katarynka sudo[6903]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:03:12 katarynka sudo[6903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:12 katarynka sudo[6905]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "services"... Mar 25 19:03:12 katarynka sudo[6905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:12 katarynka sudo[6903]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:12 katarynka sudo[6905]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "alsa_controller"... Mar 25 19:03:12 katarynka sudo[6913]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 19:03:12 katarynka sudo[6913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:12 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "wizard"... Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "networkfs"... Mar 25 19:03:12 katarynka volumio[6856]: info: Starting Udev Watcher for removable devices Mar 25 19:03:12 katarynka volumio[6856]: info: Ignoring mount for partition: boot Mar 25 19:03:12 katarynka volumio[6856]: info: Ignoring mount for partition: volumio Mar 25 19:03:12 katarynka volumio[6856]: info: Ignoring mount for partition: volumio_data Mar 25 19:03:12 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "volumio_command_line_client"... Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "upnp"... Mar 25 19:03:12 katarynka volumio[6856]: info: [1774461792956] Starting Upmpd Daemon Mar 25 19:03:12 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "my_music"... Mar 25 19:03:12 katarynka volumio[6856]: info: Loading plugin "mpd"... Mar 25 19:03:13 katarynka sudo[6913]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:13 katarynka volumio[6856]: info: Loading plugin "upnp_browser"... Mar 25 19:03:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 19:03:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:15 katarynka go-librespot[6938]: go-librespot daemon starting... Mar 25 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+01:00" level=debug msg="app state loaded" Mar 25 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+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 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+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 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+01:00" level=info msg="zeroconf server listening on port 41353" Mar 25 19:03:15 katarynka go-librespot[6939]: time="2026-03-25T19:03:15+01:00" level=debug msg="obtained new client token: AAAy0Pnbwxje/QvsbRVFDuqxLasu39PzkrnQuE2ojJIJ2s/2Y/eE44ZqZFPq6iEagEP/Pue1jHTP5PL73wj0/ozMvIjhJEL8i32R0kfjKs+SSvKo/9/dz6VEZqCPlRvO0CXTNipWtXPpiCGIjsLbLH1CQcnVO3rAWlLLGeYEtl/En7m9vjKI9vz9d+WMGAVwR1hpBh7pFjEM4ekZObKPouPLdifOonwx6Gx1W0oe6Bn+6PyC6Y1xa7506LI=" Mar 25 19:03:16 katarynka go-librespot[6939]: time="2026-03-25T19:03:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:16 katarynka go-librespot[6939]: time="2026-03-25T19:03:16+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:16 katarynka go-librespot[6939]: time="2026-03-25T19:03:16+01:00" level=debug msg="completed challenge" Mar 25 19:03:16 katarynka go-librespot[6939]: time="2026-03-25T19:03: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 19:03:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:16 katarynka volumio[6856]: info: Starting UPNP Browser Mar 25 19:03:16 katarynka volumio[6856]: info: Loading plugin "alarm-clock"... Mar 25 19:03:17 katarynka volumio[6856]: info: Loading plugin "airplay_emulation"... Mar 25 19:03:17 katarynka volumio[6856]: info: Starting Shairport Sync Mar 25 19:03:17 katarynka volumio[6856]: info: Loading plugin "last_100"... Mar 25 19:03:17 katarynka volumio[6856]: info: Loading plugin "webradio"... Mar 25 19:03:17 katarynka volumio[6856]: info: Loading plugin "i2s_dacs"... Mar 25 19:03:17 katarynka volumio[6856]: info: Loading plugin "volumiodiscovery"... Mar 25 19:03:17 katarynka volumio[6856]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:17 katarynka volumio[6856]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:17 katarynka volumio[6856]: *** WARNING *** For more information see Mar 25 19:03:17 katarynka volumio[6856]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:17 katarynka volumio[6856]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:17 katarynka volumio[6856]: *** WARNING *** For more information see Mar 25 19:03:17 katarynka node[6856]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:17 katarynka node[6856]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:17 katarynka node[6856]: *** WARNING *** For more information see Mar 25 19:03:17 katarynka node[6856]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:17 katarynka node[6856]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:17 katarynka node[6856]: *** WARNING *** For more information see Mar 25 19:03:17 katarynka volumio[6856]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 19:03:17 katarynka volumio[6856]: info: Discovery: Started advertising with name: katarynka Mar 25 19:03:17 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:03:17 katarynka volumio[6856]: info: Loading plugin "spop"... Mar 25 19:03:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 19:03:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:19 katarynka go-librespot[6949]: go-librespot daemon starting... Mar 25 19:03:19 katarynka go-librespot[6950]: time="2026-03-25T19:03:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:19 katarynka go-librespot[6950]: time="2026-03-25T19:03:19+01:00" level=debug msg="app state loaded" Mar 25 19:03:19 katarynka go-librespot[6950]: time="2026-03-25T19:03:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:19 katarynka volumio[6856]: info: Loading plugin "outputs"... Mar 25 19:03:19 katarynka volumio[6856]: info: Loading plugin "albumart"... Mar 25 19:03:19 katarynka volumio[6856]: info: Plugin example_plugin is not enabled Mar 25 19:03:19 katarynka volumio[6856]: info: Loading plugin "inputs"... Mar 25 19:03:19 katarynka volumio[6856]: info: Loading plugin "updater_comm"... Mar 25 19:03:19 katarynka volumio[6856]: info: Plugin mpdemulation is not enabled Mar 25 19:03:19 katarynka volumio[6856]: info: Loading plugin "rest_api"... Mar 25 19:03:19 katarynka volumio[6856]: info: Loading plugin "websocket"... Mar 25 19:03:19 katarynka volumio[6856]: info: Starting Socket.io Server version 1.7.4 Mar 25 19:03:19 katarynka volumio[6856]: info: Loading i18n strings for locale pl Mar 25 19:03:19 katarynka volumio[6856]: Updating browse sources language Mar 25 19:03:19 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:19 katarynka go-librespot[6950]: time="2026-03-25T19:03:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:03:19 katarynka go-librespot[6950]: time="2026-03-25T19:03:19+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 19:03:19 katarynka go-librespot[6950]: time="2026-03-25T19:03:19+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 19:03:19 katarynka go-librespot[6950]: time="2026-03-25T19:03:19+01:00" level=info msg="zeroconf server listening on port 40427" Mar 25 19:03:20 katarynka go-librespot[6950]: time="2026-03-25T19:03:20+01:00" level=debug msg="obtained new client token: AAB/GZFgDd8jg0WX3UKI/nUq5CNA2nlmi5nn62loOaPlgQ0JBbAJkY+JYjwbld4aAqyu5lVCKUbsAdy+A9Qt9JtG+pzlWJIDQhq44rBBS7gD1fuAl9J0V4LllykadqhvYZdzxjZRJCa4pZmlWwbA/gbtTttI1iEThWUZk7JcymX2/lNkQWpBuXlVHPVXSUvI4J+P+q5Fz2yMs1Z+SpdczJWkLGpG9WbHxdIJRzJQum4Zsqs4l9RP2YaE" Mar 25 19:03:20 katarynka go-librespot[6950]: time="2026-03-25T19:03:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::initPlayerControls Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:20 katarynka go-librespot[6950]: time="2026-03-25T19:03:20+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:03:20 katarynka go-librespot[6950]: time="2026-03-25T19:03:20+01:00" level=debug msg="completed challenge" Mar 25 19:03:20 katarynka volumio[6856]: Express server listening on port 3000 Mar 25 19:03:20 katarynka volumio[6856]: [Metrics] WebUI: 12s 495.05ms Mar 25 19:03:20 katarynka go-librespot[6950]: time="2026-03-25T19:03: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 19:03:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::resetVolumioState Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::getcurrentVolume Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:03:20 katarynka volumio[6856]: info: Cannot read play queue from file Mar 25 19:03:20 katarynka volumio[6856]: info: Volumio Network Manager: Network status updated: 2 Mar 25 19:03:20 katarynka volumio[6956]: Forking 3 albumart workers Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::setRepeat null single undefined Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::pushState Mar 25 19:03:20 katarynka volumio[6856]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::volumioPushState Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::setRandom null Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::pushState Mar 25 19:03:20 katarynka volumio[6856]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::volumioPushState Mar 25 19:03:20 katarynka volumio[6856]: info: Setting Device type: Raspberry PI Mar 25 19:03:20 katarynka volumio[6856]: info: Completed loading Core Plugins Mar 25 19:03:20 katarynka volumio[6856]: info: Preparing to generate the ALSA configuration file Mar 25 19:03:20 katarynka volumio[6856]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::pushState Mar 25 19:03:20 katarynka volumio[6856]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::volumioPushState Mar 25 19:03:20 katarynka volumio[6856]: info: CoreStateMachine::updateTrackBlock Mar 25 19:03:20 katarynka volumio[6856]: info: CorePlayQueue::getTrackBlock Mar 25 19:03:20 katarynka volumio[6856]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:03:21 katarynka volumio[6856]: info: Asound.conf file unchanged, so no further update is needed Mar 25 19:03:21 katarynka volumio[6856]: info: Output device has changed, restarting MPD Mar 25 19:03:21 katarynka volumio[6856]: info: Output device has changed, restarting Shairport Sync Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:21 katarynka sudo[7011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:03:21 katarynka sudo[7011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:21 katarynka sudo[7011]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:21 katarynka volumio[6856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:03:21 katarynka sudo[7013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:03:21 katarynka sudo[7013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:21 katarynka volumio[6856]: info: ___________ START PLUGINS ___________ Mar 25 19:03:21 katarynka volumio[6856]: info: ControllerMpd::onStart: Initializing MPD Mar 25 19:03:21 katarynka volumio[6856]: info: Creating MPD Configuration file Mar 25 19:03:21 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 19:03:21 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:03:21 katarynka volumio[6856]: info: [1774461801384] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:21 katarynka sudo[7021]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:03:21 katarynka sudo[7021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:21 katarynka volumio[6856]: info: UPNP Browser: Client initialized successfully Mar 25 19:03:21 katarynka sudo[7023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:03:21 katarynka sudo[7023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:21 katarynka sudo[7021]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:21 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:03:21 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:03:21 katarynka systemd[1]: mpd.service: Consumed 7.827s CPU time. Mar 25 19:03:21 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:03:21 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:03:21 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:21 katarynka volumio[6856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:03:21 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:21 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:03:21 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:03:21 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:03:21 katarynka volumio[6856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:03:21 katarynka volumio[6856]: info: [1774461801753] CoreMusicLibrary::Adding element Last_100 Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:21 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:03:21 katarynka volumio[6856]: info: [1774461801764] CoreMusicLibrary::Adding element Webradio Mar 25 19:03:21 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:21 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:03:21 katarynka volumio[6856]: info: Initializing BBC Radios Mar 25 19:03:21 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:03:21 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:21 katarynka volumio[6856]: info: Creating Spotify config file Mar 25 19:03:21 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:22 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:22] [connect] Successful connection Mar 25 19:03:22 katarynka sudo[7045]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 19:03:22 katarynka sudo[7045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 19:03:22 katarynka sudo[7045]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:22 katarynka volumio[6856]: info: Volumio Calling Home Mar 25 19:03:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 19:03:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:23 katarynka go-librespot[7070]: go-librespot daemon starting... Mar 25 19:03:23 katarynka go-librespot[7071]: time="2026-03-25T19:03:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:23 katarynka volumio[6856]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:03:23 katarynka volumio[6856]: info: Discovery: Found device katarynka Mar 25 19:03:23 katarynka sudo[7078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:03:24 katarynka sudo[7078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::volumioGetState Mar 25 19:03:24 katarynka volumio[6856]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:24 katarynka sudo[7080]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:03:24 katarynka sudo[7080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:24 katarynka volumio[6856]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:03:24 katarynka sudo[7078]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:24 katarynka sudo[7080]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:24 katarynka volumio[6856]: info: Discovery: Found device katarynka Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::volumioGetState Mar 25 19:03:24 katarynka volumio[6856]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:24 katarynka volumio[6856]: info: MPD Permissions set Mar 25 19:03:24 katarynka volumio[6856]: info: MPD Permissions set Mar 25 19:03:24 katarynka volumio[6856]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:03:24 katarynka volumio[6856]: info: CoreStateMachine::pushState Mar 25 19:03:24 katarynka volumio[6856]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::volumioPushState Mar 25 19:03:24 katarynka go-librespot[7071]: time="2026-03-25T19:03:24+01:00" level=info msg="zeroconf server listening on port 46025" Mar 25 19:03:24 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774461802 101 Mar 25 19:03:24 katarynka volumio[6856]: 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 19:03:24 katarynka volumio[6856]: info: Volumio called home Mar 25 19:03:24 katarynka volumio[6856]: info: Spotify config file written Mar 25 19:03:24 katarynka volumio[6856]: 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 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka sudo[7087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 19:03:24 katarynka sudo[7087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:24 katarynka volumio[6978]: Starting albumart workers Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 19:03:24 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 19:03:24 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:24 katarynka volumio[6976]: Starting albumart workers Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:24 katarynka volumio[6856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:24 katarynka go-librespot[7096]: go-librespot daemon starting... Mar 25 19:03:24 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:24 katarynka volumio[6856]: info: No need to fix Spotify hosts Mar 25 19:03:24 katarynka sudo[7087]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:24 katarynka go-librespot[7100]: time="2026-03-25T19:03:24+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:24 katarynka go-librespot[7100]: time="2026-03-25T19:03:24+01:00" level=debug msg="app state loaded" Mar 25 19:03:24 katarynka go-librespot[7100]: time="2026-03-25T19:03:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:25 katarynka go-librespot[7100]: time="2026-03-25T19:03:25+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 19:03:25 katarynka go-librespot[7100]: time="2026-03-25T19:03:25+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 19:03:25 katarynka go-librespot[7100]: time="2026-03-25T19:03:25+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 19:03:25 katarynka go-librespot[7100]: time="2026-03-25T19:03:25+01:00" level=info msg="zeroconf server listening on port 33287" Mar 25 19:03:25 katarynka volumio[6977]: Starting albumart workers Mar 25 19:03:25 katarynka volumio[6856]: info: Starting Shairport Sync Mar 25 19:03:25 katarynka volumio[6856]: info: Starting Shairport Sync Mar 25 19:03:26 katarynka go-librespot[7100]: time="2026-03-25T19:03:25+01:00" level=debug msg="obtained new client token: AAD432pEuIfNpgre77HGWsLBx/lfGfhjxP39ux6WNvx+tj428V5pLs6cJL7HGmiUHf5KtGsr3tkD/6z19fhrpjSRkUoi92idzo59Zh4REbpERMY/RSUsvEGBMHCJI6bwVX/nHijHesSpiK3Q0AYUSj3S0eMBYJdIBHjYA1C0aoZh+6p0+16aCdEIzNY+Ha15LAVzXA3lItlqBgcvi6Y9vRpWuCRhKQgDe8JzqO3sa25TzoL86atLN6wa6X0=" Mar 25 19:03:26 katarynka volumio[6856]: info: Starting Shairport Sync Mar 25 19:03:26 katarynka go-librespot[7100]: time="2026-03-25T19:03:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:26 katarynka sudo[7111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:03:26 katarynka sudo[7111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:26 katarynka sudo[7109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:03:26 katarynka sudo[7109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:26 katarynka go-librespot[7100]: time="2026-03-25T19:03:26+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:26 katarynka go-librespot[7100]: time="2026-03-25T19:03:26+01:00" level=debug msg="completed challenge" Mar 25 19:03:26 katarynka go-librespot[7100]: time="2026-03-25T19:03:26+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 19:03:26 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:26 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:26 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:03:26 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:03:26 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:03:26 katarynka systemd[1]: shairport-sync.service: Consumed 2.557s CPU time. Mar 25 19:03:26 katarynka sudo[7114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:03:26 katarynka sudo[7114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:26 katarynka sudo[7116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 19:03:26 katarynka sudo[7116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:26 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:03:26 katarynka sudo[7109]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:26 katarynka sudo[7111]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:26 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:03:26 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:03:26 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:03:26 katarynka volumio[6856]: info: Shairport-Sync Started Mar 25 19:03:26 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:03:26 katarynka volumio[6856]: Error adding Membership: Error: addMembership EINVAL Mar 25 19:03:26 katarynka volumio[6856]: info: Shairport-Sync Started Mar 25 19:03:26 katarynka sudo[7114]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:26 katarynka sudo[7116]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:26 katarynka volumio[6856]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 19:03:26 katarynka volumio[6856]: info: CoreCommandRouter::volumioGetState Mar 25 19:03:26 katarynka volumio[6856]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:26 katarynka volumio[6856]: info: Upmpdcli Daemon Started Mar 25 19:03:26 katarynka volumio[6856]: info: Shairport-Sync Started Mar 25 19:03:27 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 19:03:27 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 19:03:27 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:03:28 katarynka volumio[6856]: info: go-librespot daemon successfully initialized Mar 25 19:03:29 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 19:03:29 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:29 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:29 katarynka go-librespot[7173]: go-librespot daemon starting... Mar 25 19:03:29 katarynka go-librespot[7174]: time="2026-03-25T19:03:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:29 katarynka go-librespot[7174]: time="2026-03-25T19:03:29+01:00" level=debug msg="app state loaded" Mar 25 19:03:29 katarynka go-librespot[7174]: time="2026-03-25T19:03:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:30 katarynka mpd[7052]: 2026-03-25T19:03:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 19:03:30 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 19:03:30 katarynka sudo[7023]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:30 katarynka sudo[7013]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:30 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 19:03:30 katarynka volumio[6856]: info: Completed starting Core Plugins Mar 25 19:03:30 katarynka volumio[6856]: info: ------------------------------------------- Mar 25 19:03:30 katarynka volumio[6856]: info: ----- MyVolumio plugins startup ---- Mar 25 19:03:30 katarynka volumio[6856]: info: ------------------------------------------- Mar 25 19:03:30 katarynka volumio[6856]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 19:03:30 katarynka go-librespot[7174]: time="2026-03-25T19:03:30+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 19:03:30 katarynka go-librespot[7174]: time="2026-03-25T19:03:30+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 19:03:30 katarynka go-librespot[7174]: time="2026-03-25T19:03:30+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 19:03:30 katarynka go-librespot[7174]: time="2026-03-25T19:03:30+01:00" level=info msg="zeroconf server listening on port 33201" Mar 25 19:03:30 katarynka volumio[6856]: error: MPD error: The expression evaluated to a falsy value: Mar 25 19:03:30 katarynka volumio[6856]: assert.ok(self.idling) Mar 25 19:03:30 katarynka volumio[6856]: error: The expression evaluated to a falsy value: Mar 25 19:03:30 katarynka volumio[6856]: assert.ok(self.idling) Mar 25 19:03:30 katarynka go-librespot[7174]: time="2026-03-25T19:03:30+01:00" level=debug msg="obtained new client token: AACCeiLcjbJAx3/PirTd91AK1Ndg1K5uI5oW/RBqBIAUkpGyX9Db+3zYCazQ49m6b7q/YywnXrYi1ICReBynzUR04ybAX74wNlqz1gUVVNYbktbEbMa2rJ3PZS1SenO5EFJMRT/1jaj5BCmjipHYbC9cF2s+BIEGH/XynP/JmUgsMVef3V7aQpUpsOfp3JnpvQkqs+VyiNXzxbtsM54VrxqBxKws2lqFsChFejZSjggb25JPgG8IATAy/hM=" Mar 25 19:03:30 katarynka volumio[6856]: error: updateQueue error: null Mar 25 19:03:30 katarynka volumio[6856]: info: MPD running with PID7052 Mar 25 19:03:30 katarynka volumio[6856]: ,establishing connection Mar 25 19:03:30 katarynka volumio[6856]: error: updateQueue error: null Mar 25 19:03:30 katarynka go-librespot[7174]: time="2026-03-25T19:03:30+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 19:03:30 katarynka go-librespot[7174]: time="2026-03-25T19:03:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 19:03:31 katarynka go-librespot[7174]: time="2026-03-25T19:03:31+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:31 katarynka go-librespot[7174]: time="2026-03-25T19:03:31+01:00" level=debug msg="completed challenge" Mar 25 19:03:31 katarynka go-librespot[7174]: time="2026-03-25T19:03:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:03:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:31 katarynka volumio[6856]: info: Initializing connection to go-librespot Websocket Mar 25 19:03:31 katarynka volumio[6856]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:03:33 katarynka sudo[7203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:03:33 katarynka sudo[7203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:33 katarynka sudo[7205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:03:33 katarynka sudo[7205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:33 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 19:03:33 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 19:03:33 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 19:03:33 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 19:03:33 katarynka sudo[7203]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:33 katarynka sudo[7205]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:33 katarynka mpd_monitor.sh[7208]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 19:03:33 katarynka volumio[6856]: info: Successfully started MPD Monitor Mar 25 19:03:33 katarynka volumio[6856]: info: Successfully started MPD Monitor Mar 25 19:03:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 19:03:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:34 katarynka go-librespot[7212]: go-librespot daemon starting... Mar 25 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+01:00" level=debug msg="app state loaded" Mar 25 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:34 katarynka volumio[6856]: info: Initializing connection to go-librespot Websocket Mar 25 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+01:00" level=debug msg="new websocket client" Mar 25 19:03:34 katarynka volumio[6856]: info: Connection to go-librespot Websocket established Mar 25 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+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 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+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 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+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 19:03:34 katarynka go-librespot[7213]: time="2026-03-25T19:03:34+01:00" level=info msg="zeroconf server listening on port 33063" Mar 25 19:03:35 katarynka go-librespot[7213]: time="2026-03-25T19:03:35+01:00" level=debug msg="obtained new client token: AADmeBveQ6gJVWa7MasZvQZxsTFzg4y1nOlk1dtAuR3a2tWJC85LAJtvFdPIlQupO5Wv9rfc6pPR3IvzlPVbDroTJwKrZdFiPj7/Y56ra8tS3FhSI8KiVknT9ULx80y9bWVWfl/40YFgGTD2QhI9BQppQVFZo0eGsXwbOIVHbmIm7ybv6TERGVIG+KfordCS3e9F63RIcck1ujcxJWj+vMAanJkxDf6L1DnKiDiJYbByZLd0jAeX/OBB" Mar 25 19:03:35 katarynka go-librespot[7213]: time="2026-03-25T19:03:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:35 katarynka go-librespot[7213]: time="2026-03-25T19:03:35+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:35 katarynka go-librespot[7213]: time="2026-03-25T19:03:35+01:00" level=debug msg="completed challenge" Mar 25 19:03:35 katarynka volumio[6856]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 19:03:35 katarynka go-librespot[7213]: time="2026-03-25T19:03: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 19:03:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:35 katarynka volumio[6856]: info: Connection to go-librespot Websocket closed Mar 25 19:03:37 katarynka volumio[6856]: info: Getting Spotify volume Mar 25 19:03:37 katarynka volumio[6856]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:03:37 katarynka volumio[6856]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:03:37 katarynka volumio[6856]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 19:03:37 katarynka volumio[6856]: errno: -111, Mar 25 19:03:37 katarynka volumio[6856]: code: 'ECONNREFUSED', Mar 25 19:03:37 katarynka volumio[6856]: syscall: 'connect', Mar 25 19:03:37 katarynka volumio[6856]: address: '127.0.0.1', Mar 25 19:03:37 katarynka volumio[6856]: port: 9879, Mar 25 19:03:37 katarynka volumio[6856]: response: undefined Mar 25 19:03:37 katarynka volumio[6856]: } Mar 25 19:03:37 katarynka volumio[6856]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:03:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 19:03:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:38 katarynka go-librespot[7232]: go-librespot daemon starting... Mar 25 19:03:38 katarynka go-librespot[7233]: time="2026-03-25T19:03:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:38 katarynka go-librespot[7233]: time="2026-03-25T19:03:38+01:00" level=debug msg="app state loaded" Mar 25 19:03:38 katarynka go-librespot[7233]: time="2026-03-25T19:03:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:38 katarynka go-librespot[7233]: time="2026-03-25T19:03:38+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 19:03:38 katarynka go-librespot[7233]: time="2026-03-25T19:03:38+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 19:03:38 katarynka go-librespot[7233]: time="2026-03-25T19:03:38+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 19:03:39 katarynka go-librespot[7233]: time="2026-03-25T19:03:39+01:00" level=info msg="zeroconf server listening on port 43029" Mar 25 19:03:39 katarynka go-librespot[7233]: time="2026-03-25T19:03:39+01:00" level=debug msg="obtained new client token: AAAZO/FPRAcYpE/VSTleKkyIC7zpvpGKAOoV37B9Spt9mSInXuXKgdtufDWPLpYk5G+I9fKYxO+uyvCuxq5E/n77ccfn0/43eJ9p7mR6AF8lNA8CZMRl9hmeKEiAP/ijIei+4l0/gYxtCWLmhffJ3mcxgiI0LTnYwnoMACqsKGXIe1h1AXk7coL8NIOCi7UarH/YUEb/dRRSTLwNSB8WfrubDhmuZztu/r+dETyX+pRt98y8pyx/VFhW" Mar 25 19:03:39 katarynka go-librespot[7233]: time="2026-03-25T19:03:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:39 katarynka go-librespot[7233]: time="2026-03-25T19:03:39+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:39 katarynka go-librespot[7233]: time="2026-03-25T19:03:39+01:00" level=debug msg="completed challenge" Mar 25 19:03:39 katarynka go-librespot[7233]: time="2026-03-25T19:03:39+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 19:03:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:39 katarynka sudo[7242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 19:02' Mar 25 19:03:39 katarynka sudo[7242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:39 katarynka sudo[7242]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:40 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:39] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 19:03:40 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:39] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 19:03:40 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:40 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 19:03:40 katarynka systemd[1]: volumio.service: Consumed 42.882s CPU time. Mar 25 19:03:40 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:03:40 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:03:40 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 86. Mar 25 19:03:40 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:03:40 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 19:03:40 katarynka systemd[1]: volumio.service: Consumed 42.882s CPU time. Mar 25 19:03:40 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 19:03:40 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:03:42 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 19:03:42 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:42 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:42 katarynka go-librespot[7270]: go-librespot daemon starting... Mar 25 19:03:42 katarynka go-librespot[7271]: time="2026-03-25T19:03:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:42 katarynka go-librespot[7271]: time="2026-03-25T19:03:42+01:00" level=debug msg="app state loaded" Mar 25 19:03:42 katarynka go-librespot[7271]: time="2026-03-25T19:03:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:43 katarynka go-librespot[7271]: time="2026-03-25T19:03:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:03:43 katarynka go-librespot[7271]: time="2026-03-25T19:03:43+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 19:03:43 katarynka go-librespot[7271]: time="2026-03-25T19:03:43+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 19:03:43 katarynka go-librespot[7271]: time="2026-03-25T19:03:43+01:00" level=info msg="zeroconf server listening on port 42591" Mar 25 19:03:43 katarynka go-librespot[7271]: time="2026-03-25T19:03:43+01:00" level=debug msg="obtained new client token: AABP3Kjkvq2Z+PKSb2eyDh+aKwLjucPBR7Nmj3ylJxVOgqmFxd7LF8+ftiUxyzG803gDXjkYhVPzjVqTWmqCzrxRQ7kiZbbWxtXTbYdp98guLYFWKxHykLUAlUYRfo6FuCctSQZX32Q/6qenyeJq+4mxluhEKtfdu/3OttTZRVhuJ7mSbftuAnbYysmiT+W/+83WK7AH24myoXM5MylVhVM2dRy2sPNLC8xne7OGMP7BcqkiM5LGuBfB" Mar 25 19:03:43 katarynka go-librespot[7271]: time="2026-03-25T19:03:43+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 19:03:43 katarynka go-librespot[7271]: time="2026-03-25T19:03:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 19:03:44 katarynka volumio[7255]: info: ------------------------------------------- Mar 25 19:03:44 katarynka volumio[7255]: info: ----- Volumio3 ---- Mar 25 19:03:44 katarynka volumio[7255]: info: ------------------------------------------- Mar 25 19:03:44 katarynka volumio[7255]: info: ----- System startup ---- Mar 25 19:03:44 katarynka volumio[7255]: info: ------------------------------------------- Mar 25 19:03:44 katarynka go-librespot[7271]: time="2026-03-25T19:03:44+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:44 katarynka go-librespot[7271]: time="2026-03-25T19:03:44+01:00" level=debug msg="completed challenge" Mar 25 19:03:44 katarynka go-librespot[7271]: time="2026-03-25T19:03:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:03:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:45 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:44] [connect] Successful connection Mar 25 19:03:45 katarynka volumio[7255]: info: MYVOLUMIO Environment detected Mar 25 19:03:45 katarynka volumio[7255]: info: Plugin folders cleanup Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning into folder /volumio/app/plugins/ Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning category audio_interface Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning category miscellanea Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning category music_service Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning category plugins.json Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning category system_controller Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning category user_interface Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning into folder /data/plugins/ Mar 25 19:03:45 katarynka volumio[7255]: info: Scanning category music_service Mar 25 19:03:45 katarynka volumio[7255]: info: Plugin folders cleanup completed Mar 25 19:03:45 katarynka volumio[7255]: info: ------------------------------------------- Mar 25 19:03:45 katarynka volumio[7255]: info: ----- Core plugins startup ---- Mar 25 19:03:45 katarynka volumio[7255]: info: ------------------------------------------- Mar 25 19:03:45 katarynka volumio[7255]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 19:03:45 katarynka volumio[7255]: info: Adding plugin upnp to MyMusic Plugins Mar 25 19:03:45 katarynka volumio[7255]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 19:03:45 katarynka volumio[7255]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 19:03:45 katarynka volumio[7255]: info: Loading plugins from folder /data/plugins/ Mar 25 19:03:45 katarynka volumio[7255]: info: Loading plugin "system"... Mar 25 19:03:45 katarynka volumio[7255]: info: Loading plugin "appearance"... Mar 25 19:03:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 19:03:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:47 katarynka go-librespot[7293]: go-librespot daemon starting... Mar 25 19:03:47 katarynka go-librespot[7294]: time="2026-03-25T19:03:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:47 katarynka go-librespot[7294]: time="2026-03-25T19:03:47+01:00" level=debug msg="app state loaded" Mar 25 19:03:47 katarynka go-librespot[7294]: time="2026-03-25T19:03:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:47 katarynka volumio[7255]: info: Loading plugin "network"... Mar 25 19:03:47 katarynka volumio[7255]: info: Refreshing Cached IP Addresses Mar 25 19:03:47 katarynka sudo[7302]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:03:47 katarynka sudo[7302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:47 katarynka sudo[7304]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:03:47 katarynka sudo[7304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:47 katarynka sudo[7302]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:47 katarynka sudo[7304]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:47 katarynka volumio[7255]: info: Loading plugin "services"... Mar 25 19:03:47 katarynka volumio[7255]: info: Loading plugin "alsa_controller"... Mar 25 19:03:47 katarynka sudo[7314]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 19:03:47 katarynka sudo[7314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:48 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:03:48 katarynka volumio[7255]: info: Loading plugin "wizard"... Mar 25 19:03:48 katarynka volumio[7255]: info: Loading plugin "networkfs"... Mar 25 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+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 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+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 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+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 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+01:00" level=info msg="zeroconf server listening on port 36707" Mar 25 19:03:48 katarynka volumio[7255]: info: Starting Udev Watcher for removable devices Mar 25 19:03:48 katarynka volumio[7255]: info: Ignoring mount for partition: boot Mar 25 19:03:48 katarynka volumio[7255]: info: Ignoring mount for partition: volumio Mar 25 19:03:48 katarynka volumio[7255]: info: Ignoring mount for partition: volumio_data Mar 25 19:03:48 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:03:48 katarynka volumio[7255]: info: Loading plugin "volumio_command_line_client"... Mar 25 19:03:48 katarynka volumio[7255]: info: Loading plugin "upnp"... Mar 25 19:03:48 katarynka volumio[7255]: info: [1774461828294] Starting Upmpd Daemon Mar 25 19:03:48 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:03:48 katarynka volumio[7255]: info: Loading plugin "my_music"... Mar 25 19:03:48 katarynka volumio[7255]: info: Loading plugin "mpd"... Mar 25 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+01:00" level=debug msg="obtained new client token: AADNA046moAsa/t5hDMm+wa2m0ggnqoPPzC3OK66BrTK19z/ne2LpCRsccrLdmr73AJD1Kq/0BmPqRUhP5OXIZSyC8s78rYbbfkR09gs+moWnGuWyBQjF5P+UPCXfjir+WiJOBcSlhRXUbW6IUKxg+wbKryTjiT6rJ8olMDz2wGxV3rgKz+6SUud8E5Up6ayc2fA0hgFKwXs8JHwHrK1YdNiUcGDSOowlngWxy5fvSpUYlOGJdn9f5jqD0A=" Mar 25 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:48 katarynka sudo[7314]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03:48+01:00" level=debug msg="completed challenge" Mar 25 19:03:48 katarynka go-librespot[7294]: time="2026-03-25T19:03: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 19:03:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:49 katarynka volumio[7255]: info: Loading plugin "upnp_browser"... Mar 25 19:03:52 katarynka volumio[7255]: info: Starting UPNP Browser Mar 25 19:03:52 katarynka volumio[7255]: info: Loading plugin "alarm-clock"... Mar 25 19:03:52 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 19:03:52 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:52 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:52 katarynka go-librespot[7336]: go-librespot daemon starting... Mar 25 19:03:52 katarynka go-librespot[7337]: time="2026-03-25T19:03:52+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:52 katarynka go-librespot[7337]: time="2026-03-25T19:03:52+01:00" level=debug msg="app state loaded" Mar 25 19:03:52 katarynka go-librespot[7337]: time="2026-03-25T19:03:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:52 katarynka volumio[7255]: info: Loading plugin "airplay_emulation"... Mar 25 19:03:52 katarynka volumio[7255]: info: Starting Shairport Sync Mar 25 19:03:52 katarynka volumio[7255]: info: Loading plugin "last_100"... Mar 25 19:03:52 katarynka volumio[7255]: info: Loading plugin "webradio"... Mar 25 19:03:52 katarynka volumio[7255]: info: Loading plugin "i2s_dacs"... Mar 25 19:03:52 katarynka volumio[7255]: info: Loading plugin "volumiodiscovery"... Mar 25 19:03:52 katarynka volumio[7255]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:52 katarynka volumio[7255]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:52 katarynka volumio[7255]: *** WARNING *** For more information see Mar 25 19:03:52 katarynka volumio[7255]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:52 katarynka volumio[7255]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:52 katarynka volumio[7255]: *** WARNING *** For more information see Mar 25 19:03:52 katarynka node[7255]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:52 katarynka node[7255]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:52 katarynka node[7255]: *** WARNING *** For more information see Mar 25 19:03:52 katarynka node[7255]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:03:52 katarynka node[7255]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:03:52 katarynka node[7255]: *** WARNING *** For more information see Mar 25 19:03:52 katarynka volumio[7255]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 19:03:52 katarynka volumio[7255]: info: Discovery: Started advertising with name: katarynka Mar 25 19:03:52 katarynka go-librespot[7337]: time="2026-03-25T19:03:52+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 19:03:52 katarynka go-librespot[7337]: time="2026-03-25T19:03:52+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 19:03:52 katarynka go-librespot[7337]: time="2026-03-25T19:03:52+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 19:03:52 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:03:52 katarynka volumio[7255]: info: Loading plugin "spop"... Mar 25 19:03:52 katarynka go-librespot[7337]: time="2026-03-25T19:03:52+01:00" level=info msg="zeroconf server listening on port 36305" Mar 25 19:03:53 katarynka go-librespot[7337]: time="2026-03-25T19:03:53+01:00" level=debug msg="obtained new client token: AAB24RmQ0vR+8Orv7vnW3wKSm3k28bgEVFo0TV0N7NH4Y9G4e9//xBbXEKth+djb5zVnxXF1gIuHb7nSwugp3TZ/3tR4otqKAbsAFwt17ENsUHC5+JzUIO0xykUca4jVI07KZXE0dgovzULsGKydye1xkrqC18y76WvJ6hMCo/q1tCL/2/SF25XMQRlqWkm2lxRfLpXJOrSax0c42Emy790N2FWAGEO/KM2lirZhNkuemK2tEaiLuVoV8+A=" Mar 25 19:03:53 katarynka go-librespot[7337]: time="2026-03-25T19:03:53+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:53 katarynka go-librespot[7337]: time="2026-03-25T19:03:53+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:53 katarynka go-librespot[7337]: time="2026-03-25T19:03:53+01:00" level=debug msg="completed challenge" Mar 25 19:03:53 katarynka go-librespot[7337]: time="2026-03-25T19:03:53+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 19:03:53 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:53 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:54 katarynka volumio[7255]: info: Loading plugin "outputs"... Mar 25 19:03:54 katarynka volumio[7255]: info: Loading plugin "albumart"... Mar 25 19:03:54 katarynka volumio[7255]: info: Plugin example_plugin is not enabled Mar 25 19:03:54 katarynka volumio[7255]: info: Loading plugin "inputs"... Mar 25 19:03:54 katarynka volumio[7255]: info: Loading plugin "updater_comm"... Mar 25 19:03:55 katarynka volumio[7255]: info: Plugin mpdemulation is not enabled Mar 25 19:03:55 katarynka volumio[7255]: info: Loading plugin "rest_api"... Mar 25 19:03:55 katarynka volumio[7255]: info: Loading plugin "websocket"... Mar 25 19:03:55 katarynka volumio[7255]: info: Starting Socket.io Server version 1.7.4 Mar 25 19:03:55 katarynka volumio[7255]: info: Loading i18n strings for locale pl Mar 25 19:03:55 katarynka volumio[7255]: Updating browse sources language Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::initPlayerControls Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:03:55 katarynka volumio[7255]: Express server listening on port 3000 Mar 25 19:03:55 katarynka volumio[7255]: [Metrics] WebUI: 12s 590.19ms Mar 25 19:03:55 katarynka volumio[7255]: info: CoreStateMachine::resetVolumioState Mar 25 19:03:55 katarynka volumio[7255]: info: CoreStateMachine::getcurrentVolume Mar 25 19:03:55 katarynka volumio[7255]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:03:55 katarynka volumio[7255]: info: Cannot read play queue from file Mar 25 19:03:55 katarynka volumio[7255]: info: Volumio Network Manager: Network status updated: 2 Mar 25 19:03:55 katarynka volumio[7351]: Forking 3 albumart workers Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:56 katarynka volumio[7255]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:03:56 katarynka volumio[7255]: info: CoreStateMachine::pushState Mar 25 19:03:56 katarynka volumio[7255]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::volumioPushState Mar 25 19:03:56 katarynka volumio[7255]: info: CoreStateMachine::updateTrackBlock Mar 25 19:03:56 katarynka volumio[7255]: info: CorePlayQueue::getTrackBlock Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:03:56 katarynka volumio[7255]: info: CoreStateMachine::setRepeat null single undefined Mar 25 19:03:56 katarynka volumio[7255]: info: CoreStateMachine::pushState Mar 25 19:03:56 katarynka volumio[7255]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::volumioPushState Mar 25 19:03:56 katarynka volumio[7255]: info: CoreStateMachine::setRandom null Mar 25 19:03:56 katarynka volumio[7255]: info: CoreStateMachine::pushState Mar 25 19:03:56 katarynka volumio[7255]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::volumioPushState Mar 25 19:03:56 katarynka volumio[7255]: info: Setting Device type: Raspberry PI Mar 25 19:03:56 katarynka volumio[7255]: info: Completed loading Core Plugins Mar 25 19:03:56 katarynka volumio[7255]: info: Preparing to generate the ALSA configuration file Mar 25 19:03:56 katarynka volumio[7255]: info: Asound.conf file unchanged, so no further update is needed Mar 25 19:03:56 katarynka volumio[7255]: info: Output device has changed, restarting MPD Mar 25 19:03:56 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 19:03:56 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:56 katarynka sudo[7407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:03:56 katarynka sudo[7407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:56 katarynka volumio[7255]: info: Output device has changed, restarting Shairport Sync Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:56 katarynka sudo[7407]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:56 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:03:56 katarynka go-librespot[7406]: go-librespot daemon starting... Mar 25 19:03:56 katarynka sudo[7410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:03:56 katarynka sudo[7410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:56 katarynka go-librespot[7415]: time="2026-03-25T19:03:56+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:03:56 katarynka go-librespot[7415]: time="2026-03-25T19:03:56+01:00" level=debug msg="app state loaded" Mar 25 19:03:56 katarynka volumio[7255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:03:56 katarynka go-librespot[7415]: time="2026-03-25T19:03:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:03:56 katarynka volumio[7255]: info: ___________ START PLUGINS ___________ Mar 25 19:03:56 katarynka volumio[7255]: info: ControllerMpd::onStart: Initializing MPD Mar 25 19:03:56 katarynka volumio[7255]: info: Creating MPD Configuration file Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:03:56 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 19:03:56 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:03:56 katarynka volumio[7255]: info: [1774461836819] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:56 katarynka sudo[7425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:03:56 katarynka sudo[7425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:56 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:03:56 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:03:56 katarynka systemd[1]: mpd.service: Consumed 7.781s CPU time. Mar 25 19:03:56 katarynka volumio[7255]: info: UPNP Browser: Client initialized successfully Mar 25 19:03:56 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:03:56 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:03:56 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:03:56 katarynka sudo[7423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:56 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:57 katarynka sudo[7423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:57 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:03:57 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:03:57 katarynka sudo[7423]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:57 katarynka volumio[7255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:03:57 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:03:57 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:57 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:57 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:03:57 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:03:57 katarynka volumio[7255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:03:57 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:03:57 katarynka volumio[7255]: info: [1774461837204] CoreMusicLibrary::Adding element Last_100 Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:03:57 katarynka volumio[7255]: info: [1774461837223] CoreMusicLibrary::Adding element Webradio Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:03:57 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:03:57 katarynka volumio[7255]: info: Initializing BBC Radios Mar 25 19:03:57 katarynka go-librespot[7415]: time="2026-03-25T19:03:57+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 19:03:57 katarynka go-librespot[7415]: time="2026-03-25T19:03:57+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 19:03:57 katarynka go-librespot[7415]: time="2026-03-25T19:03:57+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 19:03:57 katarynka go-librespot[7415]: time="2026-03-25T19:03:57+01:00" level=info msg="zeroconf server listening on port 37931" Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:03:57 katarynka volumio-remote-updater[686]: [2026-03-25 19:03:57] [connect] Successful connection Mar 25 19:03:57 katarynka go-librespot[7415]: time="2026-03-25T19:03:57+01:00" level=debug msg="obtained new client token: AAB7KOfkdw52Y8qqMQwkgvynm7WDQGzIViAUZDcDz5IZ1GpZtOUxQn1FEMetrMNYX1eHFduszJXZtEGA6XyvzHMuQ9GEfkrdzubVtS/cicMBiAlvOXHvm3Ia6R7n94+SHfB5h1bxaWP4fH0m3Ml9AVZsuZeWXdM8Ent7Y/nxxaVM3R4hHiNh9EOoepPg9q6S1GhKcgJw60o4E83Y/vZKDZEFvmeFZeCLl3UPaQyBHdOb2HpcS7rNrsj4WJk=" Mar 25 19:03:57 katarynka volumio[7255]: info: Creating Spotify config file Mar 25 19:03:57 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:03:57 katarynka sudo[7440]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 19:03:57 katarynka sudo[7440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 19:03:57 katarynka sudo[7440]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:57 katarynka go-librespot[7415]: time="2026-03-25T19:03:57+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:03:58 katarynka go-librespot[7415]: time="2026-03-25T19:03:58+01:00" level=debug msg="completed keyexchange" Mar 25 19:03:58 katarynka go-librespot[7415]: time="2026-03-25T19:03:58+01:00" level=debug msg="completed challenge" Mar 25 19:03:58 katarynka go-librespot[7415]: time="2026-03-25T19:03:58+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 19:03:58 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:03:58 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:03:58 katarynka volumio[7255]: info: Volumio Calling Home Mar 25 19:03:59 katarynka volumio[7368]: Starting albumart workers Mar 25 19:03:59 katarynka volumio[7255]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:03:59 katarynka volumio[7255]: info: Discovery: Found device katarynka Mar 25 19:03:59 katarynka volumio[7255]: info: CoreCommandRouter::volumioGetState Mar 25 19:03:59 katarynka volumio[7255]: info: CorePlayQueue::getTrack 0 Mar 25 19:03:59 katarynka sudo[7481]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:03:59 katarynka sudo[7481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:59 katarynka sudo[7481]: pam_unix(sudo:session): session closed for user root Mar 25 19:03:59 katarynka sudo[7483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:03:59 katarynka sudo[7483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:03:59 katarynka sudo[7483]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:00 katarynka volumio[7255]: info: MPD Permissions set Mar 25 19:04:00 katarynka volumio[7255]: info: MPD Permissions set Mar 25 19:04:00 katarynka volumio[7255]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:04:00 katarynka volumio[7255]: info: CoreStateMachine::pushState Mar 25 19:04:00 katarynka volumio[7255]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::volumioPushState Mar 25 19:04:00 katarynka volumio-remote-updater[686]: [2026-03-25 19:04:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774461837 101 Mar 25 19:04:00 katarynka volumio[7255]: 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 19:04:00 katarynka volumio[7255]: info: Volumio called home Mar 25 19:04:00 katarynka volumio[7255]: info: Spotify config file written Mar 25 19:04:00 katarynka volumio[7255]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:04:00 katarynka volumio[7255]: info: Discovery: Found device katarynka Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::volumioGetState Mar 25 19:04:00 katarynka volumio[7255]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:00 katarynka sudo[7487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 19:04:00 katarynka sudo[7487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:00 katarynka volumio[7373]: Starting albumart workers Mar 25 19:04:00 katarynka volumio[7371]: Starting albumart workers Mar 25 19:04:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:00 katarynka go-librespot[7489]: go-librespot daemon starting... Mar 25 19:04:00 katarynka sudo[7487]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:00 katarynka go-librespot[7490]: time="2026-03-25T19:04:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:00 katarynka go-librespot[7490]: time="2026-03-25T19:04:00+01:00" level=debug msg="app state loaded" Mar 25 19:04:00 katarynka go-librespot[7490]: time="2026-03-25T19:04:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:00 katarynka volumio[7255]: 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 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:00 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:01 katarynka volumio[7255]: info: No need to fix Spotify hosts Mar 25 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+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 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+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 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+01:00" level=info msg="zeroconf server listening on port 34813" Mar 25 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+01:00" level=debug msg="obtained new client token: AAAa+9kL5fue2bUQuGuC87EU8K2g/6tKGd8PXHfPBl1AH72RLO6/S/ERZ6e41ILj5E1r53U4nM6fNH6tAaSL478q+cto644zDrD6l2Fp9JkN/GSNmhkUy9pX/Pg/5Mt98epyZ/OBTfmXqEpcBdbyyUKwQ5cwK4ClR+7b7K3ZWa7vLg8seCuzo9YXJJUau297q/rU3TnUNObrJj5HMcAGU/7mEmR3vHksMeEfJe3tfUgbY4wwjR6ph/MmWu4=" Mar 25 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:01 katarynka volumio[7255]: info: Starting Shairport Sync Mar 25 19:04:01 katarynka volumio[7255]: info: Starting Shairport Sync Mar 25 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+01:00" level=debug msg="completed challenge" Mar 25 19:04:01 katarynka volumio[7255]: info: Starting Shairport Sync Mar 25 19:04:01 katarynka go-librespot[7490]: time="2026-03-25T19:04:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:04:01 katarynka sudo[7514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:04:01 katarynka sudo[7514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:01 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:01 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:02 katarynka sudo[7516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:04:02 katarynka sudo[7516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:02 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:04:02 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:04:02 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:02 katarynka systemd[1]: shairport-sync.service: Consumed 2.168s CPU time. Mar 25 19:04:02 katarynka sudo[7518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:04:02 katarynka sudo[7518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:02 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:02 katarynka sudo[7514]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:02 katarynka sudo[7522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 19:04:02 katarynka sudo[7522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:02 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:04:02 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:04:02 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:02 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:02 katarynka sudo[7518]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:02 katarynka sudo[7516]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:02 katarynka volumio[7255]: info: Shairport-Sync Started Mar 25 19:04:02 katarynka volumio[7255]: Error adding Membership: Error: addMembership EINVAL Mar 25 19:04:02 katarynka sudo[7522]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:02 katarynka volumio[7255]: info: Shairport-Sync Started Mar 25 19:04:02 katarynka volumio[7255]: info: Shairport-Sync Started Mar 25 19:04:02 katarynka volumio[7255]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 19:04:02 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 19:04:02 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 19:04:02 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:04:02 katarynka volumio[7255]: info: Upmpdcli Daemon Started Mar 25 19:04:02 katarynka volumio[7255]: info: CoreCommandRouter::volumioGetState Mar 25 19:04:02 katarynka volumio[7255]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:04 katarynka volumio[7255]: info: go-librespot daemon successfully initialized Mar 25 19:04:05 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 19:04:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:05 katarynka mpd[7455]: 2026-03-25T19:04:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 19:04:05 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 19:04:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:05 katarynka go-librespot[7554]: go-librespot daemon starting... Mar 25 19:04:05 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 19:04:05 katarynka sudo[7425]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:05 katarynka sudo[7410]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+01:00" level=debug msg="app state loaded" Mar 25 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:05 katarynka volumio[7255]: info: Completed starting Core Plugins Mar 25 19:04:05 katarynka volumio[7255]: info: ------------------------------------------- Mar 25 19:04:05 katarynka volumio[7255]: info: ----- MyVolumio plugins startup ---- Mar 25 19:04:05 katarynka volumio[7255]: info: ------------------------------------------- Mar 25 19:04:05 katarynka volumio[7255]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 19:04:05 katarynka volumio[7255]: error: MPD error: The expression evaluated to a falsy value: Mar 25 19:04:05 katarynka volumio[7255]: assert.ok(self.idling) Mar 25 19:04:05 katarynka volumio[7255]: error: The expression evaluated to a falsy value: Mar 25 19:04:05 katarynka volumio[7255]: assert.ok(self.idling) Mar 25 19:04:05 katarynka volumio[7255]: info: MPD running with PID7455 Mar 25 19:04:05 katarynka volumio[7255]: ,establishing connection Mar 25 19:04:05 katarynka volumio[7255]: error: updateQueue error: null Mar 25 19:04:05 katarynka volumio[7255]: error: updateQueue error: null Mar 25 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+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 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+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 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+01:00" level=info msg="zeroconf server listening on port 35007" Mar 25 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+01:00" level=debug msg="obtained new client token: AAC712outKjQ57DRG+aUa9rBErnnclaoWT2Zcej2dePTt7sSz6Sb3/ZHoliDJr2lyEc1Iz5SS1VaaObu7WH33HxT0L8ArkIADPWACl1bTVa6y22XmndcRYgTp953OHEVJ0OuhkiByk6UXoN7lSZHLQBUgTwNajFiqtQ03Hv5J7QO2PnrYDU55hnHrSL6Z3pjeLNVMvKvYq4EpNK2lUS18tOUtSYMjx1uoM1U4+wMUw1VViw1KEacxYMzZuA=" Mar 25 19:04:05 katarynka go-librespot[7557]: time="2026-03-25T19:04:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:06 katarynka go-librespot[7557]: time="2026-03-25T19:04:06+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:06 katarynka go-librespot[7557]: time="2026-03-25T19:04:06+01:00" level=debug msg="completed challenge" Mar 25 19:04:06 katarynka go-librespot[7557]: time="2026-03-25T19:04:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:04:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:07 katarynka volumio[7255]: info: Initializing connection to go-librespot Websocket Mar 25 19:04:07 katarynka volumio[7255]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:04:08 katarynka sudo[7578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:04:08 katarynka sudo[7578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:08 katarynka sudo[7583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:04:08 katarynka sudo[7583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:08 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 19:04:08 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 19:04:08 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 19:04:08 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 19:04:08 katarynka sudo[7578]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:08 katarynka sudo[7583]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:08 katarynka mpd_monitor.sh[7586]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 19:04:08 katarynka volumio[7255]: info: Successfully started MPD Monitor Mar 25 19:04:08 katarynka volumio[7255]: info: Successfully started MPD Monitor Mar 25 19:04:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 19:04:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:09 katarynka go-librespot[7590]: go-librespot daemon starting... Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=debug msg="app state loaded" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=info msg="zeroconf server listening on port 46447" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=debug msg="obtained new client token: AAC/nrgQ6HHGHKhGj3ObjKgxkeHGURxRy7G1wItm6ko9+BNbxkcpCPOUwCzm9Yts7TZyFAkkvBaaTzjtW6+Xd808qlfqGX/oBwVXdWK7Y4oQzwTYRvx34dGpjS6RirYuCnDTFK5qIrMpijmm1kz/b8Cis6wwNkWi+kYpksPG+5JuDEC5rjo6XQoDFHTr0fh18N2OAAgoHGvf9AJh9ysulwkGxwcZVO7rl4rJrA+hdIi4l+024p2alqLueIw=" Mar 25 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+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 19:04:09 katarynka go-librespot[7591]: time="2026-03-25T19:04:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 19:04:10 katarynka go-librespot[7591]: time="2026-03-25T19:04:10+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:10 katarynka go-librespot[7591]: time="2026-03-25T19:04:10+01:00" level=debug msg="completed challenge" Mar 25 19:04:10 katarynka go-librespot[7591]: time="2026-03-25T19:04:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:04:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:10 katarynka volumio[7255]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 19:04:10 katarynka volumio[7255]: info: Initializing connection to go-librespot Websocket Mar 25 19:04:10 katarynka volumio[7255]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:04:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 19:04:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:13 katarynka go-librespot[7598]: go-librespot daemon starting... Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=debug msg="app state loaded" Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:13 katarynka volumio[7255]: info: Initializing connection to go-librespot Websocket Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=debug msg="new websocket client" Mar 25 19:04:13 katarynka volumio[7255]: info: Connection to go-librespot Websocket established Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+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 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+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 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=info msg="zeroconf server listening on port 38291" Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 19:04:13 katarynka volumio[7255]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 19:04:13 katarynka volumio[7255]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 19:04:13 katarynka volumio[7255]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 19:04:13 katarynka volumio[7255]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 19:04:13 katarynka volumio[7255]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=debug msg="obtained new client token: AAD2EabMzINang5gvMLqgKJ8JhjdfjhgZL8jvD6D2WN67QGiUGDGIvT391Tc9cMxN6EDWiLEIfyEMgzfiaLEY/uFoSTycxM6YmeS3KfhV0M69RdPZ9grQG4o4RaH7MMJ5/oMnvsQ1/6Vi6ula7dFaDpQjmqumSyN+uMKj1/s9+Hu8Osl60DFRBOynSSs24KRsT5RTH2cYO00f4p60RYD8i9kQzFNsOyu9wtO2VFlfO6rFO0E+VqoBpE+KqI=" Mar 25 19:04:13 katarynka volumio[7255]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 19:04:13 katarynka volumio[7255]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 19:04:13 katarynka volumio[7255]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 19:04:13 katarynka go-librespot[7599]: time="2026-03-25T19:04:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:14 katarynka go-librespot[7599]: time="2026-03-25T19:04:14+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:14 katarynka go-librespot[7599]: time="2026-03-25T19:04:14+01:00" level=debug msg="completed challenge" Mar 25 19:04:14 katarynka go-librespot[7599]: time="2026-03-25T19:04:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:04:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:15 katarynka volumio[7255]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 19:04:15 katarynka volumio[7255]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 19:04:15 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:15 katarynka volumio[7255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:15 katarynka volumio[7255]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 19:04:15 katarynka volumio[7255]: info: MyVolumio login type: Token Mar 25 19:04:16 katarynka volumio[7255]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 19:04:16 katarynka volumio[7255]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 19:04:17 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 19:04:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:17 katarynka go-librespot[7611]: go-librespot daemon starting... Mar 25 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+01:00" level=debug msg="app state loaded" Mar 25 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+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 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+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 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+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 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+01:00" level=info msg="zeroconf server listening on port 41407" Mar 25 19:04:17 katarynka volumio[7255]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 19:04:17 katarynka volumio[7255]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 19:04:17 katarynka volumio[7255]: info: Streaming services startup Mar 25 19:04:17 katarynka volumio[7255]: info: Starting Streaming Daemon Mar 25 19:04:17 katarynka sudo[7620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 19:04:17 katarynka sudo[7620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:17 katarynka volumio[7255]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 19:04:17 katarynka go-librespot[7612]: time="2026-03-25T19:04:17+01:00" level=debug msg="obtained new client token: AAASrAieZ5oA+eqN9gXWImSitSvOE9EWMty9Yz8QpaaEX8s1UqaJuk74tBtHpFaaMcEMMk+lDnI64e8T1QCIbNKm5GECP/Pfz/oPODE1r3CvDUVbZKEGMhqhmcCxmMp6RjuXk+60ie+6hFLhnh5HtnDAXUxEapiWScMeIUa4vBET66OOwwost4l2cFDewRKjGMHN2jbiq5RZooHdmOhJ/tOt2WCxPFU+B3WEFTl42OzuDdXTEOgT0m15HUA=" Mar 25 19:04:17 katarynka sudo[7620]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:18 katarynka go-librespot[7612]: time="2026-03-25T19:04:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:18 katarynka volumio[7255]: info: Getting Spotify volume Mar 25 19:04:18 katarynka volumio[7255]: info: Connection to go-librespot Websocket closed Mar 25 19:04:18 katarynka go-librespot[7612]: time="2026-03-25T19:04:18+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:18 katarynka go-librespot[7612]: time="2026-03-25T19:04:18+01:00" level=debug msg="completed challenge" Mar 25 19:04:18 katarynka volumio[7255]: error: Cannot start Volumio Streaming Daemon Mar 25 19:04:18 katarynka volumio[7255]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 19:04:18 katarynka volumio[7255]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 19:04:18 katarynka go-librespot[7612]: time="2026-03-25T19:04:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:04:18 katarynka volumio[7255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 25 19:04:18 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:18 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:18 katarynka volumio[7255]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:04:18 katarynka volumio[7255]: Error: socket hang up Mar 25 19:04:18 katarynka volumio[7255]: at connResetException (node:internal/errors:720:14) Mar 25 19:04:18 katarynka volumio[7255]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 19:04:18 katarynka volumio[7255]: at Socket.emit (node:events:526:35) Mar 25 19:04:18 katarynka volumio[7255]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 19:04:18 katarynka volumio[7255]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 19:04:18 katarynka volumio[7255]: code: 'ECONNRESET', Mar 25 19:04:18 katarynka volumio[7255]: response: undefined Mar 25 19:04:18 katarynka volumio[7255]: } Mar 25 19:04:18 katarynka volumio[7255]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:04:19 katarynka sudo[7654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 19:03' Mar 25 19:04:19 katarynka sudo[7654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:20 katarynka sudo[7654]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:20 katarynka volumio-remote-updater[686]: [2026-03-25 19:04:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 19:04:20 katarynka volumio-remote-updater[686]: [2026-03-25 19:04:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 19:04:20 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:20 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 19:04:20 katarynka systemd[1]: volumio.service: Consumed 48.948s CPU time. Mar 25 19:04:20 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:04:20 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:04:20 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 87. Mar 25 19:04:20 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:04:20 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 19:04:20 katarynka systemd[1]: volumio.service: Consumed 48.948s CPU time. Mar 25 19:04:20 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 19:04:20 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:04:21 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 19:04:21 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:21 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:21 katarynka go-librespot[7684]: go-librespot daemon starting... Mar 25 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+01:00" level=debug msg="app state loaded" Mar 25 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+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 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+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 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+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 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+01:00" level=info msg="zeroconf server listening on port 38799" Mar 25 19:04:21 katarynka go-librespot[7685]: time="2026-03-25T19:04:21+01:00" level=debug msg="obtained new client token: AAD42p199X5MzbeHUju8v5Ck6n0LZZFeW29J92ii4DgV+nqyPPraPLdPk024rVxpb1Z08rAImVzfcBwPKCIetKb/K4E22kMkQyBOIm+DEcaTvTSIWuQCLAtfdWqRW/ksT2sivrzrNqg8a+1F0xu+A02BLEC3LuVBFB1qg4Y+ZFL2dnRFiCtC23Giwe4YmkPobss0ExkODXLA1N5UisyH2KftZv/WW4PZS0jMZ/XTkouFCqBnFNavfUazBtY=" Mar 25 19:04:22 katarynka go-librespot[7685]: time="2026-03-25T19:04:22+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 19:04:22 katarynka go-librespot[7685]: time="2026-03-25T19:04:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 19:04:22 katarynka go-librespot[7685]: time="2026-03-25T19:04:22+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:22 katarynka go-librespot[7685]: time="2026-03-25T19:04:22+01:00" level=debug msg="completed challenge" Mar 25 19:04:22 katarynka go-librespot[7685]: time="2026-03-25T19:04:22+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 19:04:22 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:22 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:24 katarynka volumio[7669]: info: ------------------------------------------- Mar 25 19:04:24 katarynka volumio[7669]: info: ----- Volumio3 ---- Mar 25 19:04:24 katarynka volumio[7669]: info: ------------------------------------------- Mar 25 19:04:24 katarynka volumio[7669]: info: ----- System startup ---- Mar 25 19:04:24 katarynka volumio[7669]: info: ------------------------------------------- Mar 25 19:04:25 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 19:04:25 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:25 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:25 katarynka go-librespot[7698]: go-librespot daemon starting... Mar 25 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+01:00" level=debug msg="app state loaded" Mar 25 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:25 katarynka volumio-remote-updater[686]: [2026-03-25 19:04:25] [connect] Successful connection Mar 25 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+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 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+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 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+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 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+01:00" level=info msg="zeroconf server listening on port 46373" Mar 25 19:04:25 katarynka go-librespot[7699]: time="2026-03-25T19:04:25+01:00" level=debug msg="obtained new client token: AACTkx8zUzJaDlm12iZvsCzC6hJEuhQO920eZugIGZQWo0EAc7rmaCQwxy6VHC4BrrU2sKQC9UD+Nk9dt9Vp+Zu1tyuAuLChu8GyQScZlZT3eQdkzWaaOkdG7I9+OHAXI5BnOg6P1NLSGqnH26wabOSjZWcuJeLZrJjn/yUa5sn+3ecDUMIfW4300qWx6KCb5klpNnJlyut7yLaBImu/4V6yxxqkkFMsvsgf5FGzUzdsSc9ahb3i/iRBHv4=" Mar 25 19:04:26 katarynka go-librespot[7699]: time="2026-03-25T19:04:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:26 katarynka go-librespot[7699]: time="2026-03-25T19:04:26+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:26 katarynka go-librespot[7699]: time="2026-03-25T19:04:26+01:00" level=debug msg="completed challenge" Mar 25 19:04:26 katarynka volumio[7669]: info: MYVOLUMIO Environment detected Mar 25 19:04:26 katarynka go-librespot[7699]: time="2026-03-25T19:04:26+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 19:04:26 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:26 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:26 katarynka volumio[7669]: info: Plugin folders cleanup Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning into folder /volumio/app/plugins/ Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning category audio_interface Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning category miscellanea Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning category music_service Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning category plugins.json Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning category system_controller Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning category user_interface Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning into folder /data/plugins/ Mar 25 19:04:26 katarynka volumio[7669]: info: Scanning category music_service Mar 25 19:04:26 katarynka volumio[7669]: info: Plugin folders cleanup completed Mar 25 19:04:26 katarynka volumio[7669]: info: ------------------------------------------- Mar 25 19:04:26 katarynka volumio[7669]: info: ----- Core plugins startup ---- Mar 25 19:04:26 katarynka volumio[7669]: info: ------------------------------------------- Mar 25 19:04:26 katarynka volumio[7669]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 19:04:26 katarynka volumio[7669]: info: Adding plugin upnp to MyMusic Plugins Mar 25 19:04:26 katarynka volumio[7669]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 19:04:26 katarynka volumio[7669]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 19:04:26 katarynka volumio[7669]: info: Loading plugins from folder /data/plugins/ Mar 25 19:04:26 katarynka volumio[7669]: info: Loading plugin "system"... Mar 25 19:04:26 katarynka volumio[7669]: info: Loading plugin "appearance"... Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "network"... Mar 25 19:04:28 katarynka volumio[7669]: info: Refreshing Cached IP Addresses Mar 25 19:04:28 katarynka sudo[7713]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:04:28 katarynka sudo[7713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:28 katarynka sudo[7713]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "services"... Mar 25 19:04:28 katarynka sudo[7715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:04:28 katarynka sudo[7715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "alsa_controller"... Mar 25 19:04:28 katarynka sudo[7715]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:28 katarynka sudo[7723]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 19:04:28 katarynka sudo[7723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:28 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "wizard"... Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "networkfs"... Mar 25 19:04:28 katarynka volumio[7669]: info: Starting Udev Watcher for removable devices Mar 25 19:04:28 katarynka volumio[7669]: info: Ignoring mount for partition: boot Mar 25 19:04:28 katarynka volumio[7669]: info: Ignoring mount for partition: volumio Mar 25 19:04:28 katarynka volumio[7669]: info: Ignoring mount for partition: volumio_data Mar 25 19:04:28 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "volumio_command_line_client"... Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "upnp"... Mar 25 19:04:28 katarynka volumio[7669]: info: [1774461868857] Starting Upmpd Daemon Mar 25 19:04:28 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "my_music"... Mar 25 19:04:28 katarynka volumio[7669]: info: Loading plugin "mpd"... Mar 25 19:04:29 katarynka sudo[7723]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:29 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 19:04:29 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:29 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:29 katarynka go-librespot[7750]: go-librespot daemon starting... Mar 25 19:04:29 katarynka go-librespot[7751]: time="2026-03-25T19:04:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:29 katarynka go-librespot[7751]: time="2026-03-25T19:04:29+01:00" level=debug msg="app state loaded" Mar 25 19:04:29 katarynka go-librespot[7751]: time="2026-03-25T19:04:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:29 katarynka volumio[7669]: info: Loading plugin "upnp_browser"... Mar 25 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+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 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+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 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+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 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+01:00" level=info msg="zeroconf server listening on port 44651" Mar 25 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+01:00" level=debug msg="obtained new client token: AABW5ng6uWPEguaLVR2WiKYWRTvAeiNA7I2QC2R1rXGBq9Ub52uQHLuPThTR+MW6ymnS8rUQVB51J/bzfazVVhcqtRj6x+0LrmcfPLWdWXswFSXI/Cv667R4xtTGirbOBTioHqYru/M9dGwoYzxDotwR12Dq6f/+WaKIfuQyis4FILidi9pjJMrYysujv+cQTaRBDXGsDR5eNlYw0Ee453sbauO6z4c0j5fGyo0xD6sVKA7tZlGXd5jn7i4=" Mar 25 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+01:00" level=debug msg="completed challenge" Mar 25 19:04:30 katarynka go-librespot[7751]: time="2026-03-25T19:04:30+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 19:04:30 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:30 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:32 katarynka volumio[7669]: info: Starting UPNP Browser Mar 25 19:04:32 katarynka volumio[7669]: info: Loading plugin "alarm-clock"... Mar 25 19:04:32 katarynka volumio[7669]: info: Loading plugin "airplay_emulation"... Mar 25 19:04:33 katarynka volumio[7669]: info: Starting Shairport Sync Mar 25 19:04:33 katarynka volumio[7669]: info: Loading plugin "last_100"... Mar 25 19:04:33 katarynka volumio[7669]: info: Loading plugin "webradio"... Mar 25 19:04:33 katarynka volumio[7669]: info: Loading plugin "i2s_dacs"... Mar 25 19:04:33 katarynka volumio[7669]: info: Loading plugin "volumiodiscovery"... Mar 25 19:04:33 katarynka volumio[7669]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:04:33 katarynka volumio[7669]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:04:33 katarynka volumio[7669]: *** WARNING *** For more information see Mar 25 19:04:33 katarynka volumio[7669]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:04:33 katarynka volumio[7669]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:04:33 katarynka volumio[7669]: *** WARNING *** For more information see Mar 25 19:04:33 katarynka node[7669]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:04:33 katarynka node[7669]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:04:33 katarynka node[7669]: *** WARNING *** For more information see Mar 25 19:04:33 katarynka node[7669]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:04:33 katarynka node[7669]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:04:33 katarynka node[7669]: *** WARNING *** For more information see Mar 25 19:04:33 katarynka volumio[7669]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 19:04:33 katarynka volumio[7669]: info: Discovery: Started advertising with name: katarynka Mar 25 19:04:33 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:04:33 katarynka volumio[7669]: info: Loading plugin "spop"... Mar 25 19:04:33 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 19:04:33 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:33 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:33 katarynka go-librespot[7761]: go-librespot daemon starting... Mar 25 19:04:33 katarynka go-librespot[7762]: time="2026-03-25T19:04:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:33 katarynka go-librespot[7762]: time="2026-03-25T19:04:33+01:00" level=debug msg="app state loaded" Mar 25 19:04:33 katarynka go-librespot[7762]: time="2026-03-25T19:04:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:34 katarynka go-librespot[7762]: time="2026-03-25T19:04:34+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 19:04:34 katarynka go-librespot[7762]: time="2026-03-25T19:04:34+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 19:04:34 katarynka go-librespot[7762]: time="2026-03-25T19:04:34+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 19:04:34 katarynka go-librespot[7762]: time="2026-03-25T19:04:34+01:00" level=info msg="zeroconf server listening on port 45463" Mar 25 19:04:34 katarynka go-librespot[7762]: time="2026-03-25T19:04:34+01:00" level=debug msg="obtained new client token: AACsOw7JlnMC/MOtkzvk3Mjlkj+CSfdNQXQKu2Sn+y45IzWcDMzu3TW6iHWM24hG4Y3YwSETDFLEvXRZuZlvKyicVgYvuhR9EL+I24y+z5AagedOcOhpOQxA2pkUb4mynjD/6Yyx0ZYGDlMWCj2F1tCMVciHA5cSmd/naZF1g2TcmvsqqHp7GhsZWlFfXnPYQG3w+06nsII1xBpOJJMsi6mK8wkZaqbPsG0mSy8QFgRn1b+vlBXCFftnO+8=" Mar 25 19:04:34 katarynka go-librespot[7762]: time="2026-03-25T19:04:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:35 katarynka go-librespot[7762]: time="2026-03-25T19:04:35+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:35 katarynka go-librespot[7762]: time="2026-03-25T19:04:35+01:00" level=debug msg="completed challenge" Mar 25 19:04:35 katarynka go-librespot[7762]: time="2026-03-25T19:04: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 19:04:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:35 katarynka volumio[7669]: info: Loading plugin "outputs"... Mar 25 19:04:35 katarynka volumio[7669]: info: Loading plugin "albumart"... Mar 25 19:04:35 katarynka volumio[7669]: info: Plugin example_plugin is not enabled Mar 25 19:04:35 katarynka volumio[7669]: info: Loading plugin "inputs"... Mar 25 19:04:35 katarynka volumio[7669]: info: Loading plugin "updater_comm"... Mar 25 19:04:35 katarynka volumio[7669]: info: Plugin mpdemulation is not enabled Mar 25 19:04:35 katarynka volumio[7669]: info: Loading plugin "rest_api"... Mar 25 19:04:35 katarynka volumio[7669]: info: Loading plugin "websocket"... Mar 25 19:04:35 katarynka volumio[7669]: info: Starting Socket.io Server version 1.7.4 Mar 25 19:04:35 katarynka volumio[7669]: info: Loading i18n strings for locale pl Mar 25 19:04:35 katarynka volumio[7669]: Updating browse sources language Mar 25 19:04:35 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::initPlayerControls Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: Express server listening on port 3000 Mar 25 19:04:36 katarynka volumio[7669]: [Metrics] WebUI: 12s 616.93ms Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::resetVolumioState Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::getcurrentVolume Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:04:36 katarynka volumio[7669]: info: Cannot read play queue from file Mar 25 19:04:36 katarynka volumio[7669]: info: Volumio Network Manager: Network status updated: 2 Mar 25 19:04:36 katarynka volumio[7771]: Forking 3 albumart workers Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:36 katarynka volumio[7669]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::pushState Mar 25 19:04:36 katarynka volumio[7669]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::volumioPushState Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::updateTrackBlock Mar 25 19:04:36 katarynka volumio[7669]: info: CorePlayQueue::getTrackBlock Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::setRepeat null single undefined Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::pushState Mar 25 19:04:36 katarynka volumio[7669]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::volumioPushState Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::setRandom null Mar 25 19:04:36 katarynka volumio[7669]: info: CoreStateMachine::pushState Mar 25 19:04:36 katarynka volumio[7669]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:36 katarynka volumio[7669]: info: CoreCommandRouter::volumioPushState Mar 25 19:04:36 katarynka volumio[7669]: info: Setting Device type: Raspberry PI Mar 25 19:04:36 katarynka volumio[7669]: info: Completed loading Core Plugins Mar 25 19:04:36 katarynka volumio[7669]: info: Preparing to generate the ALSA configuration file Mar 25 19:04:37 katarynka volumio[7669]: info: Asound.conf file unchanged, so no further update is needed Mar 25 19:04:37 katarynka volumio[7669]: info: Output device has changed, restarting MPD Mar 25 19:04:37 katarynka volumio[7669]: info: Output device has changed, restarting Shairport Sync Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:37 katarynka sudo[7825]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:04:37 katarynka sudo[7825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:37 katarynka sudo[7825]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:37 katarynka sudo[7828]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:04:37 katarynka sudo[7828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:37 katarynka volumio[7669]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:04:37 katarynka volumio[7669]: info: ___________ START PLUGINS ___________ Mar 25 19:04:37 katarynka volumio[7669]: info: ControllerMpd::onStart: Initializing MPD Mar 25 19:04:37 katarynka volumio[7669]: info: Creating MPD Configuration file Mar 25 19:04:37 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 19:04:37 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:04:37 katarynka volumio[7669]: info: [1774461877295] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:04:37 katarynka sudo[7838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:04:37 katarynka sudo[7836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:04:37 katarynka sudo[7836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:37 katarynka sudo[7838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:37 katarynka sudo[7836]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:37 katarynka volumio[7669]: info: UPNP Browser: Client initialized successfully Mar 25 19:04:37 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:04:37 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:04:37 katarynka systemd[1]: mpd.service: Consumed 7.686s CPU time. Mar 25 19:04:37 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:04:37 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:04:37 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:37 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:04:37 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:04:37 katarynka volumio[7669]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:37 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:04:37 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:04:37 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:04:37 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:04:37 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:04:37 katarynka volumio[7669]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:04:37 katarynka volumio[7669]: info: [1774461877665] CoreMusicLibrary::Adding element Last_100 Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:04:37 katarynka volumio[7669]: info: [1774461877674] CoreMusicLibrary::Adding element Webradio Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:04:37 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:04:37 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:04:37 katarynka volumio[7669]: info: Initializing BBC Radios Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:37 katarynka volumio[7669]: info: Creating Spotify config file Mar 25 19:04:37 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:38 katarynka volumio-remote-updater[686]: [2026-03-25 19:04:38] [connect] Successful connection Mar 25 19:04:38 katarynka sudo[7853]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 19:04:38 katarynka sudo[7853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 19:04:38 katarynka sudo[7853]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 19:04:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:38 katarynka go-librespot[7869]: go-librespot daemon starting... Mar 25 19:04:38 katarynka go-librespot[7870]: time="2026-03-25T19:04:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:39 katarynka volumio[7669]: info: Volumio Calling Home Mar 25 19:04:39 katarynka go-librespot[7870]: time="2026-03-25T19:04:39+01:00" level=info msg="zeroconf server listening on port 45031" Mar 25 19:04:40 katarynka volumio[7669]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:04:40 katarynka volumio[7669]: info: Discovery: Found device katarynka Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::volumioGetState Mar 25 19:04:40 katarynka sudo[7895]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:04:40 katarynka sudo[7897]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:04:40 katarynka sudo[7895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:40 katarynka sudo[7897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:40 katarynka volumio[7669]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:40 katarynka sudo[7895]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:40 katarynka sudo[7897]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:40 katarynka volumio[7669]: info: MPD Permissions set Mar 25 19:04:40 katarynka volumio[7669]: info: MPD Permissions set Mar 25 19:04:40 katarynka volumio[7669]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:04:40 katarynka volumio[7669]: info: CoreStateMachine::pushState Mar 25 19:04:40 katarynka volumio[7669]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::volumioPushState Mar 25 19:04:40 katarynka volumio[7669]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:04:40 katarynka volumio[7669]: info: Discovery: Found device katarynka Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::volumioGetState Mar 25 19:04:40 katarynka volumio[7669]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:40 katarynka volumio-remote-updater[686]: [2026-03-25 19:04:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774461878 101 Mar 25 19:04:40 katarynka volumio[7669]: 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 19:04:40 katarynka volumio[7669]: info: Volumio called home Mar 25 19:04:40 katarynka volumio[7669]: info: Spotify config file written Mar 25 19:04:40 katarynka sudo[7901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 19:04:40 katarynka sudo[7901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:40 katarynka volumio[7792]: Starting albumart workers Mar 25 19:04:40 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 19:04:40 katarynka systemd[1]: go-librespot-daemon.service: Killing process 7872 (go-librespot) with signal SIGKILL. Mar 25 19:04:40 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 19:04:40 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:40 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:40 katarynka volumio[7669]: 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 19:04:40 katarynka go-librespot[7903]: go-librespot daemon starting... Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:40 katarynka sudo[7901]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:40 katarynka go-librespot[7904]: time="2026-03-25T19:04:40+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:40+01:00" level=debug msg="app state loaded" Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7788]: Starting albumart workers Mar 25 19:04:41 katarynka volumio[7793]: Starting albumart workers Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:04:41 katarynka volumio[7669]: info: No need to fix Spotify hosts Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+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 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+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 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+01:00" level=info msg="zeroconf server listening on port 43909" Mar 25 19:04:41 katarynka volumio[7669]: info: Starting Shairport Sync Mar 25 19:04:41 katarynka volumio[7669]: info: Starting Shairport Sync Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+01:00" level=debug msg="obtained new client token: AABPiMryPRj4daIVOkKaqhHm/hSKUzbu4Zze1Stdi8JeZZkP9EaCFqfl0edjuZp6mMgHFON2nIthuJ54oSfUk0AAxegHvx3nqGUGVq/QvFpP4EguVcol6bQOo5s+UHDvbZoMWsiF3sxQUUTt3FlJ9z34dm2gr02BYAt5yQ+vX1g/ChMPv7irzipZtDIdN/P67XPGoGcE4RTnzkyOZX5mV3jY29QeHz8XdHbh/Xt1ItOvakV6OWW7iU3szIM=" Mar 25 19:04:41 katarynka sudo[7923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:04:41 katarynka sudo[7923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:41 katarynka volumio[7669]: info: Starting Shairport Sync Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:41 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:04:41 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:04:41 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:41 katarynka systemd[1]: shairport-sync.service: Consumed 2.352s CPU time. Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:41 katarynka sudo[7925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:04:41 katarynka go-librespot[7904]: time="2026-03-25T19:04:41+01:00" level=debug msg="completed challenge" Mar 25 19:04:42 katarynka sudo[7925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:42 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:42 katarynka go-librespot[7904]: time="2026-03-25T19:04:42+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 19:04:42 katarynka sudo[7929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:04:42 katarynka sudo[7929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:42 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:42 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:42 katarynka sudo[7923]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:42 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:04:42 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:04:42 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:42 katarynka sudo[7932]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 19:04:42 katarynka volumio[7669]: info: Shairport-Sync Started Mar 25 19:04:42 katarynka sudo[7932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:42 katarynka volumio[7669]: Error adding Membership: Error: addMembership EINVAL Mar 25 19:04:42 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:42 katarynka sudo[7929]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:42 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:04:42 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:04:42 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:42 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:04:42 katarynka sudo[7925]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:42 katarynka sudo[7932]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:43 katarynka volumio[7669]: info: Upmpdcli Daemon Started Mar 25 19:04:43 katarynka volumio[7669]: info: Shairport-Sync Started Mar 25 19:04:43 katarynka volumio[7669]: info: Shairport-Sync Started Mar 25 19:04:43 katarynka volumio[7669]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 19:04:43 katarynka volumio[7669]: info: CoreCommandRouter::volumioGetState Mar 25 19:04:43 katarynka volumio[7669]: info: CorePlayQueue::getTrack 0 Mar 25 19:04:43 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 19:04:43 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 19:04:43 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:04:44 katarynka volumio[7669]: info: go-librespot daemon successfully initialized Mar 25 19:04:45 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 19:04:45 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:45 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:45 katarynka go-librespot[7972]: go-librespot daemon starting... Mar 25 19:04:45 katarynka go-librespot[7973]: time="2026-03-25T19:04:45+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:45 katarynka go-librespot[7973]: time="2026-03-25T19:04:45+01:00" level=debug msg="app state loaded" Mar 25 19:04:45 katarynka go-librespot[7973]: time="2026-03-25T19:04:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:46 katarynka mpd[7868]: 2026-03-25T19:04:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 19:04:46 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 19:04:46 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 19:04:46 katarynka sudo[7838]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:46 katarynka sudo[7828]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:46 katarynka volumio[7669]: info: Completed starting Core Plugins Mar 25 19:04:46 katarynka volumio[7669]: info: ------------------------------------------- Mar 25 19:04:46 katarynka volumio[7669]: info: ----- MyVolumio plugins startup ---- Mar 25 19:04:46 katarynka volumio[7669]: info: ------------------------------------------- Mar 25 19:04:46 katarynka volumio[7669]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 19:04:46 katarynka volumio[7669]: error: MPD error: The expression evaluated to a falsy value: Mar 25 19:04:46 katarynka volumio[7669]: assert.ok(self.idling) Mar 25 19:04:46 katarynka volumio[7669]: error: The expression evaluated to a falsy value: Mar 25 19:04:46 katarynka volumio[7669]: assert.ok(self.idling) Mar 25 19:04:46 katarynka volumio[7669]: error: updateQueue error: null Mar 25 19:04:46 katarynka volumio[7669]: info: MPD running with PID7868 Mar 25 19:04:46 katarynka volumio[7669]: ,establishing connection Mar 25 19:04:46 katarynka volumio[7669]: error: updateQueue error: null Mar 25 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+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 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+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 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+01:00" level=info msg="zeroconf server listening on port 35471" Mar 25 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+01:00" level=debug msg="obtained new client token: AACWCPAAkuCVITIyyXvDEspwJNglzi3QjkN5oEZ46DylmDDCSLHlsLkbxGTLdYFDBc5z42kiPmGpNI9MV5g65uj6J/usaotsenQGWOf38U4Znt3bdxkYHNfST37uzo1qOPWqmflZ/cLbaWRIdjaQ9K/1iEwlAdVmP99Pwugwie13khbCJoQoOF063peel0WquI+RQalOWvJBLzaJK3VbpBgq40Xw1zD1tzyOPJKeRkAf2cNQ9/Sp190J7Xs=" Mar 25 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+01:00" level=debug msg="completed challenge" Mar 25 19:04:46 katarynka go-librespot[7973]: time="2026-03-25T19:04:46+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 19:04:46 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:46 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:47 katarynka volumio[7669]: info: Initializing connection to go-librespot Websocket Mar 25 19:04:47 katarynka volumio[7669]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:04:49 katarynka sudo[8002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:04:49 katarynka sudo[8002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:49 katarynka sudo[8004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:04:49 katarynka sudo[8004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:04:49 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 19:04:49 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 19:04:49 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 19:04:49 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 19:04:49 katarynka sudo[8002]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:49 katarynka mpd_monitor.sh[8007]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 19:04:49 katarynka volumio[7669]: info: Successfully started MPD Monitor Mar 25 19:04:49 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 19:04:49 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 19:04:49 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 19:04:49 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 19:04:49 katarynka sudo[8004]: pam_unix(sudo:session): session closed for user root Mar 25 19:04:49 katarynka volumio[7669]: info: Successfully started MPD Monitor Mar 25 19:04:49 katarynka mpd_monitor.sh[8010]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 19:04:49 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 19:04:49 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:50 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:50 katarynka go-librespot[8014]: go-librespot daemon starting... Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=debug msg="app state loaded" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+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 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+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 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=info msg="zeroconf server listening on port 36075" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=debug msg="obtained new client token: AAAHoaoAiqdLnm/05oMWQTcyeDXjYp5Wj0Gq30v7+vODF5/t48PlYFUI3/ugdcc2LogU4L2XXUBVGWuow5gCeC2TadHo5TxcDRuOrCI/rvu4SNn3Rhj1r+t9SgizwwbVAL2TkU71pcJZhGplVM4JwuYC5MDbewwkz74KqSH/GvzZQjOi3KGbDOpF3ur7LYCWUVOJGIuPJctdGsdR+8AkD87se0NjWdGwO+pE8m3ctY/BaAbAa0EFxJgVTAA=" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:50 katarynka volumio[7669]: info: Initializing connection to go-librespot Websocket Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=debug msg="new websocket client" Mar 25 19:04:50 katarynka volumio[7669]: info: Connection to go-librespot Websocket established Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+01:00" level=debug msg="completed challenge" Mar 25 19:04:50 katarynka go-librespot[8015]: time="2026-03-25T19:04:50+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 19:04:50 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:50 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:50 katarynka volumio[7669]: info: Connection to go-librespot Websocket closed Mar 25 19:04:51 katarynka volumio[7669]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 19:04:53 katarynka volumio[7669]: info: Getting Spotify volume Mar 25 19:04:53 katarynka volumio[7669]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:04:53 katarynka volumio[7669]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:04:53 katarynka volumio[7669]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 19:04:53 katarynka volumio[7669]: errno: -111, Mar 25 19:04:53 katarynka volumio[7669]: code: 'ECONNREFUSED', Mar 25 19:04:53 katarynka volumio[7669]: syscall: 'connect', Mar 25 19:04:53 katarynka volumio[7669]: address: '127.0.0.1', Mar 25 19:04:53 katarynka volumio[7669]: port: 9879, Mar 25 19:04:53 katarynka volumio[7669]: response: undefined Mar 25 19:04:53 katarynka volumio[7669]: } Mar 25 19:04:53 katarynka volumio[7669]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:04:53 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 19:04:53 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:53 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:04:54 katarynka go-librespot[8033]: go-librespot daemon starting... Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=debug msg="app state loaded" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+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 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+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 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=info msg="zeroconf server listening on port 38645" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=debug msg="obtained new client token: AABZzFwRrVVQb1P8nROdTqOm1BgKOrsnYI1wSF7R5M8pAMmd1oDfLdMgBV2RU3pag6mGyUuD5wZ0snyyDy7AFNm3Bsu3jgexytZARdnOUKnsNh3pPiM0tBa8X+q6X7e0cEHp7vZvaHA7Mvdf2uS/LbctE7gmEAtx5p5akg+YlgiF9uO1y8jrWDm8Ij+/wIO4zo/uwVKUKCUOB5lwbnJ8tBxEG4z0SqniN7HyxHYwZwEozVVR6Xrwg/+yank=" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=debug msg="completed keyexchange" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+01:00" level=debug msg="completed challenge" Mar 25 19:04:54 katarynka go-librespot[8034]: time="2026-03-25T19:04:54+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 19:04:54 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:04:54 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:04:55 katarynka sudo[8045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 19:03' Mar 25 19:04:55 katarynka sudo[8045]: 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"