Oct 12 05:37:00 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:00 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:01 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4564. Oct 12 05:37:01 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:01 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:01 bcik go-librespot[3844]: go-librespot daemon starting... Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=debug msg="app state loaded" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02: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]" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02: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]" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02: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]" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=info msg="zeroconf server listening on port 39603" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=debug msg="obtained new client token: AAEpD7fqK0+jEum9kryQgDI9Jkqkv5Z9atze3nWKM4R3Zg9z6sIOgQxA7/AvVXXnLOl5t1N8wWN2py1jwSw2h5fHrUKOVupemXLqw9kS4NeH/Ib3+G5NbqQlxMWxgU+ssSKnOH3Mo1jZZ7RkPms0aaPfJ87Z4NMheP8HYMtpcabbePRnjJ3KpybTEMBA4UwY/A1fwNF4eYuw6aC8IIRIOdOQqGnGrG5go6pu4RKc388ljP/NTa/AmcQ=" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=debug msg="completed challenge" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:01 bcik go-librespot[3845]: time="2026-10-12T05:37:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 05:37:03 bcik volumio[3598]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 05:37:03 bcik volumio[3598]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 05:37:03 bcik volumio[3598]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 05:37:03 bcik volumio[3598]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 05:37:03 bcik volumio[3598]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 05:37:03 bcik volumio[3598]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 05:37:03 bcik volumio[3598]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 05:37:03 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:03 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:03 bcik volumio[3598]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 05:37:03 bcik volumio[3598]: info: MyVolumio login type: Token Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 05:37:03 bcik volumio[3598]: info: Streaming services startup Oct 12 05:37:03 bcik volumio[3598]: info: Starting Streaming Daemon Oct 12 05:37:03 bcik sudo[3869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:37:03 bcik sudo[3869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:03 bcik volumio[3598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 05:37:03 bcik sudo[3869]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:03 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:03 bcik sudo[3876]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:37:03 bcik sudo[3876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:03 bcik sudo[3878]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:37:03 bcik sudo[3878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:03 bcik volumio[3598]: error: Cannot start Volumio Streaming Daemon Oct 12 05:37:03 bcik volumio[3598]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:37:03 bcik volumio[3598]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:37:03 bcik sudo[3878]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:03 bcik sudo[3876]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:03 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:03 bcik sudo[3882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 05:37:03 bcik sudo[3882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:03 bcik sudo[3882]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:03 bcik volumio[3598]: info: Upmpdcli Daemon Started Oct 12 05:37:03 bcik volumio[3598]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 05:37:04 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4565. Oct 12 05:37:04 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:04 bcik volumio[3598]: info: MyVolumio token set successfully Oct 12 05:37:04 bcik volumio[3598]: info: MYVOLUMIO: Adding device Oct 12 05:37:04 bcik volumio[3598]: info: MYVOLUMIO: Evaluating Server Oct 12 05:37:04 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:04 bcik go-librespot[3886]: go-librespot daemon starting... Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=debug msg="app state loaded" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02: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]" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02: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]" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02: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]" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=info msg="zeroconf server listening on port 42741" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=debug msg="obtained new client token: AAGwnMtIe+dnHv4Xdt4mnzkCNIF2HoXqEVWIygF12XSSlKUth+eCE1lOAyhCuFsytRF/SQkPC4MxUP22OA9XLxb6/89o42oTfMEId5cilf2MLg4/PVtrT4s5wWBVeNngYOLBN/cIwyxhhOsj4s4QkU0mRtCm4t4VEPx6N7tNiylxD2R7y0pIVS1dEBaB3OdZmkPso6SOUuxUALsMbt9mmMzdJNk6dZEmqu2boNPv6Ng5uTVnri6wZw0=" Oct 12 05:37:04 bcik volumio[3598]: info: MyVolumio status changed Oct 12 05:37:04 bcik volumio[3598]: info: Streaming services startup Oct 12 05:37:04 bcik volumio[3598]: info: Starting Streaming Daemon Oct 12 05:37:04 bcik volumio[3598]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 05:37:04 bcik volumio[3598]: info: Removing audio output: Oct 12 05:37:04 bcik volumio[3598]: info: Stoppping Tunnel 1 Oct 12 05:37:04 bcik sudo[3915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:37:04 bcik sudo[3915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:04 bcik sudo[3917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 05:37:04 bcik sudo[3917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik sudo[3915]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:04 bcik volumio[3598]: error: Cannot start Volumio Streaming Daemon Oct 12 05:37:04 bcik volumio[3598]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:37:04 bcik volumio[3598]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:04 bcik sudo[3917]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:04 bcik volumio[3598]: info: Remote SSH Stopped Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:04 bcik go-librespot[3887]: time="2026-10-12T05:37:04+02:00" level=debug msg="completed challenge" Oct 12 05:37:05 bcik go-librespot[3887]: time="2026-10-12T05:37:05+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:05 bcik go-librespot[3887]: time="2026-10-12T05:37:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:05 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:05 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:05 bcik volumio[3598]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:37:05 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:05 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:05 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:05 bcik volumio[3598]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:37:06 bcik volumio[3598]: info: Updating MyVolumio device info Oct 12 05:37:06 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:06 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:06 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:06 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:06 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:07 bcik volumio[3598]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:37:08 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4566. Oct 12 05:37:08 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:08 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:08 bcik go-librespot[3920]: go-librespot daemon starting... Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=debug msg="app state loaded" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02: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]" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02: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]" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02: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]" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=info msg="zeroconf server listening on port 38135" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=debug msg="obtained new client token: AAH/RaQw7WR7xsMsULSbyKF92sgS8/yIfYIwJ1BDEjsGGS+XZUmC9FQTjyomJtqGOF57Q0804kyxhcUrBLOSxfcMg09AtwWztTfQ6AkKwWzUcGXgHSYeIeL7z2Zvz3Fm0vKs7vm+aRECIwZczEn0cJlN8UKJwjfnNmzx9wJBGi4M/UeVbstGFxZDMzQ3J3sXSokpzKOpXrMXd8DbB8Mkm2HBqkOL8zVlSX1VgYU2YJlcUXvoESQvu7s=" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=debug msg="completed challenge" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:08 bcik go-librespot[3921]: time="2026-10-12T05:37:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:08 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:08 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:09 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:09 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:09 bcik volumio[3598]: info: MYVOLUMIO: Adding device Oct 12 05:37:09 bcik volumio[3598]: info: MYVOLUMIO: Evaluating Server Oct 12 05:37:10 bcik volumio[3598]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:37:10 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:10 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:10 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:11 bcik volumio[3598]: info: Updating MyVolumio device info Oct 12 05:37:11 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:11 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:11 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:11 bcik volumio[3598]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:37:11 bcik volumio[3598]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:37:11 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4567. Oct 12 05:37:11 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:11 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:11 bcik go-librespot[3948]: go-librespot daemon starting... Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02:00" level=debug msg="app state loaded" Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02: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]" Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02: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]" Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02: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]" Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02:00" level=info msg="zeroconf server listening on port 36621" Oct 12 05:37:11 bcik go-librespot[3949]: time="2026-10-12T05:37:11+02:00" level=debug msg="obtained new client token: AAEOg5nS7k0dthLGDJf/DITnPxQld4xfZTa7TB06LzHuCwX1+8xCvhKdT4BEov2SfGSJmx+5eP4yLJZkvT5NWrTJqEdGR9TfttgwCAQclMc5OZOFVY5P4mz+LUM2E/R7UiBButpnHDmuYEChoo5aILk8oaUCNayxIDTB8k6F2+mIdh+02clGXQCKDz+/ltFEj8pkRbjmUyaYhDFeIiNccIm9pjfJec8pSS6MrNumvpksYZmt3+m5WFE=" Oct 12 05:37:12 bcik go-librespot[3949]: time="2026-10-12T05:37:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:12 bcik go-librespot[3949]: time="2026-10-12T05:37:12+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:12 bcik go-librespot[3949]: time="2026-10-12T05:37:12+02:00" level=debug msg="completed challenge" Oct 12 05:37:12 bcik go-librespot[3949]: time="2026-10-12T05:37:12+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:12 bcik go-librespot[3949]: time="2026-10-12T05:37:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:12 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:12 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:12 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:12 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:15 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:15 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4568. Oct 12 05:37:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:15 bcik go-librespot[3972]: go-librespot daemon starting... Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=debug msg="app state loaded" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02: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]" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02: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]" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02: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]" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=info msg="zeroconf server listening on port 42775" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=debug msg="obtained new client token: AAGqR9F7w/yvaOtVQaNS7EmPoueA3G2uNEgaTspTiklkE5EwhKKLitG3P5woAzsTbmD9zQ/pO6TuGdXVd8iQwWMf0Dq8QhdWnaaTxiI5Dr1aWf/rYFBg4Sau03Dju9upRLNdJOq2VgjtQVvVbXzourH4B2xXs/ghOaw2a4VjZ6nxIozqgMFc893SrwxNBl3D7DCDip16Q8FldGNwT7Jb4+CkspRZoB2Z3jgEn4JQ2//LdVexn/r2ymI=" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=debug msg="completed challenge" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:15 bcik go-librespot[3973]: time="2026-10-12T05:37:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:15 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:15 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:18 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 05:37:18 bcik volumio[3598]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:37:18 bcik volumio[3598]: info: CoreCommandRouter::volumioGetState Oct 12 05:37:18 bcik volumio[3598]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:18 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:18 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4569. Oct 12 05:37:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:19 bcik go-librespot[3983]: go-librespot daemon starting... Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=debug msg="app state loaded" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02: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]" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02: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]" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02: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]" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=info msg="zeroconf server listening on port 44333" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=debug msg="obtained new client token: AAHKhjIZwAqQjW/op4ETjOFengYgDvVYK0SenZFqHJd5BIHmbZ7sHW72//35u8ngLaOfrySRftLpINeBeL0862lOysxWFYkcUyQQjj+pRv0rnbKpZrHYDENGxrRlI5mbCCw8X6rdpjCgWVIiAtzEm8cYimXh5haiT7lmgJvyrhSLEBlOS9pPaSryE/3o2IL+ZWNviRCIJ/5eAw0OrFfmAKjzIongj53lFDlPVsSEvTTZmiohcxI9" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=debug msg="completed challenge" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:19 bcik go-librespot[3984]: time="2026-10-12T05:37:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:19 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:19 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:21 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:21 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4570. Oct 12 05:37:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:22 bcik go-librespot[3994]: go-librespot daemon starting... Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02:00" level=debug msg="app state loaded" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02: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]" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02: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]" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02: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]" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02:00" level=info msg="zeroconf server listening on port 40285" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02:00" level=debug msg="obtained new client token: AAFj2JL0yP5UKnHAQVllkan75wds+vFfyKslD/RFdCvcfL7zjiY+52rWzge9vfOSHQbwxyM6/hnicOsFAfvGg/PlKKX4QxPCRnBRYD9f5w0qAykrP2rbQC8MQj+UZJAVlNxdr2WOHa5gpzN+zBqHozGtaqwjPub7x+j6mwO5boFSwz8kwKT1D3S70UQoyppF1kGlGCUrl8wmPbr9MZNE+/1IG7X0iYG2AZM/IQ4+m9dDZKkRimXOejM=" Oct 12 05:37:22 bcik go-librespot[3995]: time="2026-10-12T05:37:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:23 bcik go-librespot[3995]: time="2026-10-12T05:37:23+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:23 bcik go-librespot[3995]: time="2026-10-12T05:37:23+02:00" level=debug msg="completed challenge" Oct 12 05:37:23 bcik go-librespot[3995]: time="2026-10-12T05:37:23+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:23 bcik go-librespot[3995]: time="2026-10-12T05:37:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:23 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:23 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:37:23 bcik volumio[3598]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 12 05:37:23 bcik volumio[3598]: info: Completed starting MyVolumio Plugin Oct 12 05:37:23 bcik volumio[3598]: [Metrics] CommandRouter: 30s 747.57ms Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::volumiosetStartupVolume Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::Close All Modals sent Oct 12 05:37:23 bcik volumio[3598]: info: CoreCommandRouter::Close All Modals sent Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 05:37:24 bcik volumio-remote-updater[9031]: Test mode disabled Oct 12 05:37:24 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 12 05:37:24 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 12 05:37:24 bcik volumio[3598]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 05:37:24 bcik volumio[3598]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 12 05:37:24 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:24 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4571. Oct 12 05:37:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:26 bcik go-librespot[4024]: go-librespot daemon starting... Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=debug msg="app state loaded" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02: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]" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02: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]" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02: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]" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=info msg="zeroconf server listening on port 40207" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=debug msg="obtained new client token: AAGlsF2LxtZlMwcMi2bLL+EjATLUWk8wM65MSNfHZ6ypGnZyM4BFfKw3pmX/w1duq9O5j4SZrS5wUpjTReMKBIy2gs50hGgVhi3GjYhhE4FsF8FT97Wz2oUfkE1w8gJmo0eL5C5o5XQ7VVRaNfgL0b2xnLItQaw4hWImz+3y8OM5J8IywVqyYcXDQcIfi/KzkN9qCO3/Yuk+LnIP8GDP5uCzEbQXVV6148C6JGiZpujN/ebXXIg28B4=" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=debug msg="completed challenge" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:26 bcik go-librespot[4025]: time="2026-10-12T05:37:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:26 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:26 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:27 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:27 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:29 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4572. Oct 12 05:37:29 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:29 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:29 bcik go-librespot[4034]: go-librespot daemon starting... Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02:00" level=debug msg="app state loaded" Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02: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]" Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02: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]" Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02: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]" Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02:00" level=info msg="zeroconf server listening on port 34837" Oct 12 05:37:29 bcik go-librespot[4035]: time="2026-10-12T05:37:29+02:00" level=debug msg="obtained new client token: AAF//n+c3kGpl/r6YalwK5c2H1HH/qKofVOWuxRr2NENW1oz1icAsXqk6RT/LlNb89nU/+3mmerHAB4HOZH2UGpEPu5zMLUZXgbggKYJIikyYcjz9oAlUU/WmDNyMflKuivAyE8JejDi2u8GFrXEgNLoe8nuW5FeuFR2u3NfQNBFybBtExsh1YMz2LPdNjy8yOU2PChTGlrm5GvY9zwPUHXcNRVJcLYyGM+oVjcWm0BuBJV9/FF0ZBk=" Oct 12 05:37:30 bcik go-librespot[4035]: time="2026-10-12T05:37:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:30 bcik go-librespot[4035]: time="2026-10-12T05:37:30+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:30 bcik go-librespot[4035]: time="2026-10-12T05:37:30+02:00" level=debug msg="completed challenge" Oct 12 05:37:30 bcik go-librespot[4035]: time="2026-10-12T05:37:30+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:30 bcik go-librespot[4035]: time="2026-10-12T05:37:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:30 bcik volumio[3598]: info: BOOT COMPLETED Oct 12 05:37:30 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:30 bcik volumio[3598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4573. Oct 12 05:37:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:33 bcik go-librespot[4058]: go-librespot daemon starting... Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=debug msg="app state loaded" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02: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]" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02: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]" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02: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]" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=info msg="zeroconf server listening on port 32955" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=debug msg="obtained new client token: AAFMGcCeKhPGiFu1OF4X+u9RJwwICKfRdord1AwCr0F0AHnsfU9fNsJPWJlKCc+PS2tooMIe4+uqD0VWFSsNbL9kaJIt+TCur8G2Arz7I/x4Otzb7GQRHgkptpGMhaJ2QXGYMmKWGGl2fCiscSBYNOFJfAmyHFYUrQ1jyzRoEyQQmm1T3oTPRe8EgNBhr2gC/edGo/No2OlYqvtQVegVF28eV3+Isb3YA6BNwrFoJHKqlrSYQlrgSFo=" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:33 bcik volumio[3598]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=debug msg="new websocket client" Oct 12 05:37:33 bcik volumio[3598]: info: Connection to go-librespot Websocket established Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=debug msg="completed challenge" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:33 bcik go-librespot[4059]: time="2026-10-12T05:37:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:33 bcik volumio[3598]: info: Connection to go-librespot Websocket closed Oct 12 05:37:33 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:33 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:36 bcik volumio[3598]: info: Getting Spotify volume Oct 12 05:37:36 bcik volumio[3598]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:37:36 bcik volumio[3598]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:36 bcik volumio[3598]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 05:37:36 bcik volumio[3598]: errno: -111, Oct 12 05:37:36 bcik volumio[3598]: code: 'ECONNREFUSED', Oct 12 05:37:36 bcik volumio[3598]: syscall: 'connect', Oct 12 05:37:36 bcik volumio[3598]: address: '127.0.0.1', Oct 12 05:37:36 bcik volumio[3598]: port: 9879, Oct 12 05:37:36 bcik volumio[3598]: response: undefined Oct 12 05:37:36 bcik volumio[3598]: } Oct 12 05:37:36 bcik volumio[3598]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:37:36 bcik sudo[4082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:36' Oct 12 05:37:36 bcik sudo[4082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:36 bcik sudo[4082]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:36 bcik volumio-remote-updater[9031]: [2026-10-12 05:37:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 05:37:36 bcik volumio-remote-updater[9031]: [2026-10-12 05:37:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 05:37:36 bcik volumio5-onboarding[1483]: time=2026-10-12T05:37:36.733+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 05:37:36 bcik volumio5-onboarding[1483]: time=2026-10-12T05:37:36.733+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 12 05:37:36 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:36 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4574. Oct 12 05:37:36 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:36 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:36 bcik go-librespot[4087]: go-librespot daemon starting... Oct 12 05:37:36 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 05:37:36 bcik systemd[1]: volumio.service: Consumed 6.540s CPU time. Oct 12 05:37:36 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=debug msg="app state loaded" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:36 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02: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]" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02: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]" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02: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]" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=info msg="zeroconf server listening on port 45899" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=debug msg="obtained new client token: AAH7V7b8vZpkAzXwEjzlE90/RDsiEL0qXVv+F1wqC8O4IgVUnh9GaVF8svu3xVrxNq4glqja5GIXpZ0cfrSL2vIouWw7IHerpqzwkm5y9OgP/SVvWAWO3beAcJVAag8ZwhWiIqufZ1sXwyzES4Lg/Fc4pxXCy+v9dKPXHetzanEisOz2CRAVTlgc5xTHeGkGbUufG6oZUZRNdRgHYnFhpsBmTt7UroVF2tMv05kXd+P1gP4kX5ywmyM=" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=debug msg="completed challenge" Oct 12 05:37:36 bcik go-librespot[4088]: time="2026-10-12T05:37:36+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:37 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21817. Oct 12 05:37:37 bcik go-librespot[4088]: time="2026-10-12T05:37:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:37 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:37:37 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 05:37:37 bcik systemd[1]: volumio.service: Consumed 6.540s CPU time. Oct 12 05:37:37 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 05:37:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:37 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:37:37 bcik volumio[4104]: info: ------------------------------------------- Oct 12 05:37:37 bcik volumio[4104]: info: ----- Volumio3 ---- Oct 12 05:37:37 bcik volumio[4104]: info: ------------------------------------------- Oct 12 05:37:37 bcik volumio[4104]: info: ----- System startup ---- Oct 12 05:37:37 bcik volumio[4104]: info: ------------------------------------------- Oct 12 05:37:37 bcik volumio[4104]: info: MYVOLUMIO Environment detected Oct 12 05:37:37 bcik volumio[4104]: info: Plugin folders cleanup Oct 12 05:37:37 bcik volumio[4104]: info: Scanning into folder /volumio/app/plugins/ Oct 12 05:37:37 bcik volumio[4104]: info: Scanning category audio_interface Oct 12 05:37:37 bcik volumio[4104]: info: Scanning category miscellanea Oct 12 05:37:37 bcik volumio[4104]: info: Scanning category music_service Oct 12 05:37:37 bcik volumio[4104]: info: Scanning category plugins.json Oct 12 05:37:37 bcik volumio[4104]: info: Scanning category system_controller Oct 12 05:37:37 bcik volumio[4104]: info: Scanning category user_interface Oct 12 05:37:37 bcik volumio[4104]: info: Scanning into folder /data/plugins/ Oct 12 05:37:37 bcik volumio[4104]: info: Scanning category music_service Oct 12 05:37:37 bcik volumio[4104]: info: Plugin folders cleanup completed Oct 12 05:37:37 bcik volumio[4104]: info: ------------------------------------------- Oct 12 05:37:37 bcik volumio[4104]: info: ----- Core plugins startup ---- Oct 12 05:37:37 bcik volumio[4104]: info: ------------------------------------------- Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 05:37:37 bcik volumio[4104]: info: Adding plugin upnp to MyMusic Plugins Oct 12 05:37:37 bcik volumio[4104]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 05:37:37 bcik volumio[4104]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugins from folder /data/plugins/ Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "system"... Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "appearance"... Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "network"... Oct 12 05:37:37 bcik volumio[4104]: info: Refreshing Cached IP Addresses Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "services"... Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "volumio5onboarding"... Oct 12 05:37:37 bcik sudo[4132]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:37:37 bcik sudo[4134]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:37:37 bcik sudo[4132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:37 bcik sudo[4134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "alsa_controller"... Oct 12 05:37:37 bcik sudo[4132]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:37 bcik sudo[4134]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:37 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "wizard"... Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "networkfs"... Oct 12 05:37:37 bcik volumio[4104]: info: Starting Udev Watcher for removable devices Oct 12 05:37:37 bcik volumio[4104]: info: Ignoring mount for partition: boot Oct 12 05:37:37 bcik volumio[4104]: info: Ignoring mount for partition: volumio Oct 12 05:37:37 bcik volumio[4104]: info: Ignoring mount for partition: volumio_data Oct 12 05:37:37 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "volumio_command_line_client"... Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "upnp"... Oct 12 05:37:37 bcik volumio[4104]: info: [1791776257861] Starting Upmpd Daemon Oct 12 05:37:37 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "my_music"... Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "mpd"... Oct 12 05:37:37 bcik volumio[4104]: info: Loading plugin "upnp_browser"... Oct 12 05:37:38 bcik volumio[4104]: info: Starting UPNP Browser Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "alarm-clock"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "airplay_emulation"... Oct 12 05:37:38 bcik volumio[4104]: info: Starting Shairport Sync Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "last_100"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "webradio"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "i2s_dacs"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "volumiodiscovery"... Oct 12 05:37:38 bcik volumio[4104]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:37:38 bcik volumio[4104]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:37:38 bcik volumio[4104]: *** WARNING *** For more information see Oct 12 05:37:38 bcik volumio[4104]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:37:38 bcik volumio[4104]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:37:38 bcik volumio[4104]: *** WARNING *** For more information see Oct 12 05:37:38 bcik node[4104]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:37:38 bcik node[4104]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:37:38 bcik node[4104]: *** WARNING *** For more information see Oct 12 05:37:38 bcik node[4104]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:37:38 bcik node[4104]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:37:38 bcik node[4104]: *** WARNING *** For more information see Oct 12 05:37:38 bcik volumio[4104]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 05:37:38 bcik volumio[4104]: info: Discovery: Started advertising with name: Bącik Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "spop"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "outputs"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "albumart"... Oct 12 05:37:38 bcik volumio[4104]: info: Plugin example_plugin is not enabled Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "inputs"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "updater_comm"... Oct 12 05:37:38 bcik volumio[4104]: info: Plugin mpdemulation is not enabled Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "rest_api"... Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "websocket"... Oct 12 05:37:38 bcik volumio[4104]: info: Starting Socket.io Server version 1.7.4 Oct 12 05:37:38 bcik volumio[4104]: info: Loading plugin "radio_browser"... Oct 12 05:37:38 bcik volumio[4164]: Forking 3 albumart workers Oct 12 05:37:38 bcik volumio[4104]: info: Loading i18n strings for locale pl Oct 12 05:37:38 bcik volumio[4104]: Updating browse sources language Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::initPlayerControls Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: Express server listening on port 3000 Oct 12 05:37:38 bcik volumio[4104]: [Metrics] WebUI: 1s 286.60ms Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::resetVolumioState Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::getcurrentVolume Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:37:38 bcik volumio[4104]: info: Volumio Network Manager: Network status updated: 1 Oct 12 05:37:38 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: Reloading queue from file Oct 12 05:37:38 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::setRepeat false single undefined Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::pushState Oct 12 05:37:38 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioPushState Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::setRandom false Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::pushState Oct 12 05:37:38 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioPushState Oct 12 05:37:38 bcik volumio[4104]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 05:37:38 bcik volumio[4104]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 05:37:38 bcik volumio[4104]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 05:37:38 bcik volumio[4104]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::pushState Oct 12 05:37:38 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioPushState Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::updateTrackBlock Oct 12 05:37:38 bcik volumio[4104]: info: CorePlayQueue::getTrackBlock Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:37:38 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:37:38 bcik volumio[4104]: info: Setting Device type: Raspberry PI Oct 12 05:37:38 bcik volumio[4104]: info: Completed loading Core Plugins Oct 12 05:37:38 bcik volumio[4104]: info: Preparing to generate the ALSA configuration file Oct 12 05:37:38 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:37:38 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:37:38 bcik volumio[4104]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:37:38 bcik volumio[4104]: info: CoreStateMachine::pushState Oct 12 05:37:38 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioPushState Oct 12 05:37:38 bcik volumio[4104]: info: Asound.conf file unchanged, so no further update is needed Oct 12 05:37:38 bcik volumio[4104]: info: Output device has changed, restarting MPD Oct 12 05:37:38 bcik volumio[4104]: info: Output device has changed, restarting Shairport Sync Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:38 bcik sudo[4221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:37:38 bcik sudo[4221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:38 bcik sudo[4221]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:38 bcik sudo[4222]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:37:38 bcik sudo[4222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:38 bcik volumio[4104]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:37:38 bcik volumio[4104]: info: ___________ START PLUGINS ___________ Oct 12 05:37:38 bcik volumio[4104]: info: ControllerMpd::onStart: Initializing MPD Oct 12 05:37:38 bcik volumio[4104]: info: Creating MPD Configuration file Oct 12 05:37:38 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 05:37:38 bcik sudo[4230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 05:37:38 bcik sudo[4232]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:37:38 bcik volumio[4104]: info: [1791776258802] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 05:37:38 bcik sudo[4230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:37:38 bcik sudo[4232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:38 bcik sudo[4232]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:38 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:37:38 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:37:38 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:37:38 bcik volumio[4104]: info: UPNP Browser: Client initialized successfully Oct 12 05:37:38 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:37:38 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:37:38 bcik sudo[4234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:38 bcik sudo[4234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:38 bcik volumio[4104]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:38 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:37:38 bcik volumio[4104]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:37:38 bcik volumio[4104]: info: [1791776258837] CoreMusicLibrary::Adding element Last_100 Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:37:38 bcik volumio[4104]: info: [1791776258838] CoreMusicLibrary::Adding element Webradio Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:37:38 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:37:38 bcik volumio[4104]: info: Initializing BBC Radios Oct 12 05:37:38 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:37:38 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:37:38 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:37:38 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:37:38 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:37:38 bcik sudo[4230]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:38 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:37:38 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:38 bcik volumio[4104]: info: Creating Spotify config file Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:38 bcik sudo[4257]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 05:37:38 bcik sudo[4257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 05:37:38 bcik volumio[4174]: Starting albumart workers Oct 12 05:37:38 bcik sudo[4257]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:38 bcik volumio[4175]: Starting albumart workers Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:37:38 bcik volumio[4104]: info: [1791776258960] CoreMusicLibrary::Adding element Radio Browser Oct 12 05:37:38 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:37:38 bcik volumio[4104]: Cannot find translation for source Radio Browser Oct 12 05:37:38 bcik volumio[4104]: info: Volumio Calling Home Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:37:39 bcik volumio[4104]: info: MPD Permissions set Oct 12 05:37:39 bcik volumio[4104]: info: MPD Permissions set Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 12 05:37:39 bcik volumio[4104]: info: Spotify config file written Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik sudo[4269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 05:37:39 bcik sudo[4269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:39 bcik volumio[4176]: Starting albumart workers Oct 12 05:37:39 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:39 bcik go-librespot[4273]: go-librespot daemon starting... Oct 12 05:37:39 bcik sudo[4269]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=debug msg="app state loaded" Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:37:39 bcik volumio[4104]: info: No need to fix Spotify hosts Oct 12 05:37:39 bcik volumio[4104]: info: Volumio called home Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: info: Starting Shairport Sync Oct 12 05:37:39 bcik sudo[4297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:37:39 bcik sudo[4297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02: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]" Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02: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]" Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02: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]" Oct 12 05:37:39 bcik volumio[4104]: info: Starting Shairport Sync Oct 12 05:37:39 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:37:39 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:37:39 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:37:39 bcik systemd[1]: shairport-sync.service: Consumed 1.554s CPU time. Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=info msg="zeroconf server listening on port 43397" Oct 12 05:37:39 bcik volumio[4104]: info: Starting Shairport Sync Oct 12 05:37:39 bcik sudo[4304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:37:39 bcik sudo[4304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:39 bcik sudo[4306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:37:39 bcik sudo[4306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:39 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:37:39 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:37:39 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:37:39 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:37:39 bcik sudo[4297]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:39 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:37:39 bcik sudo[4304]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=debug msg="obtained new client token: AAGaGUB3qepb/BtMfdoDuT8XuBaLSHGzVclteiOPS9qty8Mhr+uPLO+ZUH9UGJWpP6wSNI17FTcSByC3tcmcO4M50isoG7Ln9vHP8oC5vnDrQ9B5z/7yoV16iwQl5DAIWFssvuNC9bjwY2cJ4jfczSAwNhvsbbJmbLM+DedRsF8SLPdVbES/X0GImbsJQmKc4eiFQjPaGPNRRI25fn1tBCqAx5Yd1JPgzB3qQPvjfY1HHSLM8a1FOm4=" Oct 12 05:37:39 bcik sudo[4306]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:39 bcik volumio[4104]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:39 bcik volumio[4104]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:37:39 bcik volumio[4104]: info: Discovery: Found device Bącik Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::volumioGetState Oct 12 05:37:39 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:39 bcik volumio[4104]: info: Shairport-Sync Started Oct 12 05:37:39 bcik volumio[4104]: Error adding Membership: Error: addMembership EINVAL Oct 12 05:37:39 bcik volumio[4104]: info: Shairport-Sync Started Oct 12 05:37:39 bcik volumio[4104]: info: Shairport-Sync Started Oct 12 05:37:39 bcik volumio[4104]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:37:39 bcik volumio[4104]: info: Discovery: Found device Bącik Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::volumioGetState Oct 12 05:37:39 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: info: CoreCommandRouter::volumioGetState Oct 12 05:37:39 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=debug msg="completed challenge" Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:39 bcik go-librespot[4277]: time="2026-10-12T05:37:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:39 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:39 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:39 bcik mpd[4264]: 2026-10-12T05:37:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 05:37:39 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 05:37:39 bcik sudo[4234]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:39 bcik sudo[4222]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:39 bcik volumio[4104]: info: Completed starting Core Plugins Oct 12 05:37:39 bcik volumio[4104]: info: ------------------------------------------- Oct 12 05:37:39 bcik volumio[4104]: info: ----- MyVolumio plugins startup ---- Oct 12 05:37:39 bcik volumio[4104]: info: ------------------------------------------- Oct 12 05:37:39 bcik volumio[4104]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 05:37:39 bcik volumio[4104]: error: MPD error: The expression evaluated to a falsy value: Oct 12 05:37:39 bcik volumio[4104]: assert.ok(self.idling) Oct 12 05:37:39 bcik volumio[4104]: error: The expression evaluated to a falsy value: Oct 12 05:37:39 bcik volumio[4104]: assert.ok(self.idling) Oct 12 05:37:39 bcik volumio[4104]: info: MPD running with PID4264 Oct 12 05:37:39 bcik volumio[4104]: ,establishing connection Oct 12 05:37:39 bcik volumio[4104]: error: updateQueue error: null Oct 12 05:37:39 bcik volumio[4104]: error: updateQueue error: null Oct 12 05:37:41 bcik volumio-remote-updater[9031]: [2026-10-12 05:37:41] [connect] Successful connection Oct 12 05:37:41 bcik volumio-remote-updater[9031]: [2026-10-12 05:37:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791776261 101 Oct 12 05:37:41 bcik volumio[4104]: 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: 3 Oct 12 05:37:42 bcik volumio[4104]: info: go-librespot daemon successfully initialized Oct 12 05:37:42 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4575. Oct 12 05:37:42 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:42 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:42 bcik go-librespot[4340]: go-librespot daemon starting... Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=debug msg="app state loaded" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02: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]" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02: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]" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02: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]" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=info msg="zeroconf server listening on port 45503" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=debug msg="obtained new client token: AAHR5uFNbpSmDSxK4vPHA8TKjHYkuqb3EvTfnBZHw7VwR3NjKBg4mcxJLAjOsuRjqlIbbystUUXh82oJ/3noDa/jcL6ggziIDn8yK3BETWwh2yUHvXvgeTfe2rRm0M8sLZxO8ZiBOuljOmS0/XPkcXsVJl9PFZHNeAgYBcJLqTbqSZE5jkkITdeuKYUgV48/5ikD7lLWnRm+4x7JCWJQ4TWug1pp+bhYP4bbHju3M1Nm1hitTxemh9I=" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02: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" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=debug msg="completed challenge" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:42 bcik go-librespot[4341]: time="2026-10-12T05:37:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:42 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:42 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:44 bcik volumio[4104]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 05:37:45 bcik volumio[4104]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:45 bcik volumio[4104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:46 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4576. Oct 12 05:37:46 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:46 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:46 bcik go-librespot[4350]: go-librespot daemon starting... Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=debug msg="app state loaded" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02: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]" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02: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]" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02: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]" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=info msg="zeroconf server listening on port 33983" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=debug msg="obtained new client token: AAFzZaBThxON7qfa84tfuodrkOO6cE6vWGYruZlosVOPN3CfIDQiU3m8YpxhHIBbsvEuxzZ7+gudhpmpuphEZsqdpX5mEL9bggZCLLEwWIi83hFowrVDGYYFD4reGuLU8HavpOl2MrfwI+bnEeal2xqvqV3RTx84ERSY+0WCRpMMq+FQfa9q09Q71dXzcAwO/2yXIo3u1MO1wpuoVDbP3Hpnr14nPsKyZYgEhLVTJ8apLe5ar5Hv" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=debug msg="completed challenge" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:46 bcik go-librespot[4351]: time="2026-10-12T05:37:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:46 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:46 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 05:37:47 bcik volumio[4104]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 05:37:47 bcik volumio[4104]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 05:37:47 bcik volumio[4104]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 05:37:47 bcik volumio[4104]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 05:37:47 bcik volumio[4104]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 05:37:47 bcik volumio[4104]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 05:37:47 bcik volumio[4104]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 05:37:47 bcik volumio[4104]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 05:37:48 bcik volumio[4104]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 05:37:48 bcik volumio[4104]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 05:37:48 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:48 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:48 bcik volumio[4104]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 05:37:48 bcik volumio[4104]: info: MyVolumio login type: Token Oct 12 05:37:48 bcik volumio[4104]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 05:37:48 bcik volumio[4104]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 05:37:48 bcik volumio[4104]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 05:37:48 bcik volumio[4104]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 05:37:48 bcik volumio[4104]: info: Streaming services startup Oct 12 05:37:48 bcik volumio[4104]: info: Starting Streaming Daemon Oct 12 05:37:48 bcik sudo[4375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:37:48 bcik sudo[4375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:48 bcik volumio[4104]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 05:37:48 bcik sudo[4375]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:48 bcik volumio[4104]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:48 bcik sudo[4382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:37:48 bcik sudo[4382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:48 bcik sudo[4382]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:48 bcik sudo[4384]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:37:48 bcik volumio[4104]: error: Cannot start Volumio Streaming Daemon Oct 12 05:37:48 bcik sudo[4384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:48 bcik volumio[4104]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:37:48 bcik volumio[4104]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:37:48 bcik sudo[4384]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:48 bcik volumio[4104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:48 bcik sudo[4389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 05:37:48 bcik sudo[4389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:48 bcik sudo[4389]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:48 bcik volumio[4104]: info: Upmpdcli Daemon Started Oct 12 05:37:48 bcik volumio[4104]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 05:37:49 bcik volumio[4104]: info: MyVolumio token set successfully Oct 12 05:37:49 bcik volumio[4104]: info: MYVOLUMIO: Adding device Oct 12 05:37:49 bcik volumio[4104]: info: MYVOLUMIO: Evaluating Server Oct 12 05:37:49 bcik volumio[4104]: info: MyVolumio status changed Oct 12 05:37:49 bcik volumio[4104]: info: Streaming services startup Oct 12 05:37:49 bcik volumio[4104]: info: Starting Streaming Daemon Oct 12 05:37:49 bcik volumio[4104]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 05:37:49 bcik volumio[4104]: info: Removing audio output: Oct 12 05:37:49 bcik volumio[4104]: info: Stoppping Tunnel 1 Oct 12 05:37:49 bcik sudo[4412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:37:49 bcik sudo[4412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:49 bcik sudo[4414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 05:37:49 bcik sudo[4414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:37:49 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:49 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:49 bcik sudo[4412]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:49 bcik volumio[4104]: error: Cannot start Volumio Streaming Daemon Oct 12 05:37:49 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:49 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:49 bcik volumio[4104]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:37:49 bcik volumio[4104]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:37:49 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:49 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:37:49 bcik sudo[4414]: pam_unix(sudo:session): session closed for user root Oct 12 05:37:49 bcik volumio[4104]: info: Remote SSH Stopped Oct 12 05:37:49 bcik volumio[4104]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:37:49 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:49 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:49 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:49 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4577. Oct 12 05:37:49 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:49 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:49 bcik go-librespot[4417]: go-librespot daemon starting... Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=debug msg="app state loaded" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02: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]" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02: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]" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02: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]" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=info msg="zeroconf server listening on port 45101" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=debug msg="obtained new client token: AAEpXBNwv1c+jHcpzD186uPCiX8jp/LzVUZBYV/VJYGvLdgMJRSjR8gftAjhPwQNlo9U1AoPCqXxHkXF1HzvT4UjQSxU+1UgCUm1c6lGig1QHBoI8OewlzbCg4wfEHbpErCgjpsIg30IfzU2T5P4dFHo3DFGlhUXwrF7phalDjnTEE+J/eos3SqFlHnfoDSQAqqW8v64g1KI6HFZJbKThlCVgUzC3Ldy/sW4IzEfQR8VdmeeWkBbm5w=" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=debug msg="completed challenge" Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:49 bcik volumio[4104]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:37:49 bcik go-librespot[4418]: time="2026-10-12T05:37:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:49 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:49 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:50 bcik volumio[4104]: info: Updating MyVolumio device info Oct 12 05:37:50 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:50 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:50 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:50 bcik volumio[4104]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:37:51 bcik volumio[4104]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:51 bcik volumio[4104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:53 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4578. Oct 12 05:37:53 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:53 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:53 bcik go-librespot[4427]: go-librespot daemon starting... Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=debug msg="app state loaded" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02: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]" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02: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]" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02: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]" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=info msg="zeroconf server listening on port 41243" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=debug msg="obtained new client token: AAF9OGbrq1w7zp08P35TgEO9qs9Mlk58JxkpS4RB/O90YMXmgFSENt8Lf5T8MBQSMj7g3gQCaaqaFT1h5feVxMM2E68u7uCuutkjpf5BZZmUWgfoPTKncchucjTG1Ep0wHh7pxmN0rO+yx1NEIA8qIlXQwxEEgYRJ3hNS7++mqfd4tVC4pJZdLn3UC52IHkEj+gORcoDEfl3kk327AeRCwZz0eutc+oboa4DTh6u7zijs+wv9u+l" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02: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" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=debug msg="completed challenge" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:53 bcik go-librespot[4428]: time="2026-10-12T05:37:53+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:53 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:53 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:53 bcik volumio[4104]: info: MYVOLUMIO: Adding device Oct 12 05:37:53 bcik volumio[4104]: info: MYVOLUMIO: Evaluating Server Oct 12 05:37:54 bcik volumio[4104]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:54 bcik volumio[4104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:37:54 bcik volumio[4104]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:37:54 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:54 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:54 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:54 bcik volumio[4104]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:37:55 bcik volumio[4104]: info: Updating MyVolumio device info Oct 12 05:37:55 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:55 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:55 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:37:55 bcik volumio[4104]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:37:56 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4579. Oct 12 05:37:56 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:56 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:37:56 bcik go-librespot[4456]: go-librespot daemon starting... Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=debug msg="app state loaded" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02: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]" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02: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]" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02: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]" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=info msg="zeroconf server listening on port 34887" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=debug msg="obtained new client token: AAHTmhxoYjX2dmDSnm+W0A9VPV7QlB6N56hy9lLD9a6+WzfKRNfb8aPJiN1tOp6GArrxmGnQwTQNlHs/CKrwVdLrX8qdoDarvtmT8quxCrxtXT9/7E/9LQaI6+R+8OFrSqP91V210O+6Ei0HSEufdkUzqU2HxE9cLjFVIH2JlsaadxA1R5Hx/nBlZcRjT4Ch4pE96jiCPp3buyeCUG5y2b41ib8Euld9cd0sH1xUegSecEqK+zKvA+A=" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=debug msg="completed keyexchange" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=debug msg="completed challenge" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:37:56 bcik go-librespot[4457]: time="2026-10-12T05:37:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:37:56 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:37:56 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:37:57 bcik volumio[4104]: info: Initializing connection to go-librespot Websocket Oct 12 05:37:57 bcik volumio[4104]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:00 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4580. Oct 12 05:38:00 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:00 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:00 bcik go-librespot[4481]: go-librespot daemon starting... Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="app state loaded" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02: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]" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02: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]" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02: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]" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="zeroconf server listening on port 44793" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="obtained new client token: AAEw4d61bZqIKd6Rbt+hrIEkWDrE3LmuSXJTWPjoewexDqvVfCRygjla6upAJdL3UQs8Xh7h68W4xJ0q8no/n5Y2cvTw8VV3HMkmfMlK4ahf/VnU2tmM7371Bers78x6ieqZYdQYPMoKT2LoL1ajHmPR69h62mosYOv3bEv3GV6Ee/jXi9eOXGxsi7MRi8rOME2FQ34m3p6st4DBioZW+ytz//Lvoioy09UCIrgcNqlrJL+k4u0J" Oct 12 05:38:00 bcik volumio[4104]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="new websocket client" Oct 12 05:38:00 bcik volumio[4104]: info: Connection to go-librespot Websocket established Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="completed challenge" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:00 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:00 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:00 bcik volumio[4104]: info: Connection to go-librespot Websocket closed Oct 12 05:38:03 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 05:38:03 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:38:03 bcik volumio[4104]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:03 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:03 bcik volumio[4104]: info: Getting Spotify volume Oct 12 05:38:03 bcik volumio[4104]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:03 bcik volumio[4104]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:03 bcik volumio[4104]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 05:38:03 bcik volumio[4104]: errno: -111, Oct 12 05:38:03 bcik volumio[4104]: code: 'ECONNREFUSED', Oct 12 05:38:03 bcik volumio[4104]: syscall: 'connect', Oct 12 05:38:03 bcik volumio[4104]: address: '127.0.0.1', Oct 12 05:38:03 bcik volumio[4104]: port: 9879, Oct 12 05:38:03 bcik volumio[4104]: response: undefined Oct 12 05:38:03 bcik volumio[4104]: } Oct 12 05:38:03 bcik volumio[4104]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:03 bcik sudo[4506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:37' Oct 12 05:38:03 bcik sudo[4506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:03 bcik sudo[4506]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:03 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 05:38:03 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 05:38:03 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:03.477+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 05:38:03 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:03.478+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 12 05:38:03 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:03 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4581. Oct 12 05:38:03 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:03 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:03 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 05:38:03 bcik systemd[1]: volumio.service: Consumed 6.381s CPU time. Oct 12 05:38:03 bcik go-librespot[4511]: go-librespot daemon starting... Oct 12 05:38:03 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="app state loaded" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:03 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02: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]" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02: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]" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02: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]" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="zeroconf server listening on port 39055" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="obtained new client token: AAHU63xeToRYnb6diunbfvZ6BXChgQWtUSq1Os/bdhi3XfllQmCTbMzUwNuYT7313laDt2435z9jbxDk5IQdoPLkwWzzAN6RUnY5bMz9ZQdsKslB8KRjDUc6vPsWzuKcQBch6plTf7pmPxHnedlXtRJQ3UPdvgpOMzQDWkIeB8/3yLsw2OK1aBMop6giMnjgfTZBAuLBeqPU4p4jjzhFXaP/pgnM8ge4n8ExrjEEN60U8NQ4OcrEPlI=" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02: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" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="completed challenge" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:03 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21818. Oct 12 05:38:03 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:03 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 05:38:03 bcik systemd[1]: volumio.service: Consumed 6.381s CPU time. Oct 12 05:38:03 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:03 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: ----- Volumio3 ---- Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: ----- System startup ---- Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: MYVOLUMIO Environment detected Oct 12 05:38:04 bcik volumio[4531]: info: Plugin folders cleanup Oct 12 05:38:04 bcik volumio[4531]: info: Scanning into folder /volumio/app/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category audio_interface Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category miscellanea Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category music_service Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category plugins.json Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category system_controller Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category user_interface Oct 12 05:38:04 bcik volumio[4531]: info: Scanning into folder /data/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category music_service Oct 12 05:38:04 bcik volumio[4531]: info: Plugin folders cleanup completed Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: ----- Core plugins startup ---- Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Adding plugin upnp to MyMusic Plugins Oct 12 05:38:04 bcik volumio[4531]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 05:38:04 bcik volumio[4531]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugins from folder /data/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "system"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "appearance"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "network"... Oct 12 05:38:04 bcik volumio[4531]: info: Refreshing Cached IP Addresses Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "services"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "volumio5onboarding"... Oct 12 05:38:04 bcik sudo[4559]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:04 bcik sudo[4559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:04 bcik sudo[4561]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:04 bcik sudo[4561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:04 bcik sudo[4559]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "alsa_controller"... Oct 12 05:38:04 bcik sudo[4561]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:04 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "wizard"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "networkfs"... Oct 12 05:38:04 bcik volumio[4531]: info: Starting Udev Watcher for removable devices Oct 12 05:38:04 bcik volumio[4531]: info: Ignoring mount for partition: boot Oct 12 05:38:04 bcik volumio[4531]: info: Ignoring mount for partition: volumio Oct 12 05:38:04 bcik volumio[4531]: info: Ignoring mount for partition: volumio_data Oct 12 05:38:04 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "volumio_command_line_client"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "upnp"... Oct 12 05:38:04 bcik volumio[4531]: info: [1791776284610] Starting Upmpd Daemon Oct 12 05:38:04 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "my_music"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "mpd"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "upnp_browser"... Oct 12 05:38:04 bcik volumio[4531]: info: Starting UPNP Browser Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "alarm-clock"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "airplay_emulation"... Oct 12 05:38:04 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "last_100"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "webradio"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "i2s_dacs"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "volumiodiscovery"... Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik node[4531]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik node[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik node[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik node[4531]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik node[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik node[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik volumio[4531]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 05:38:05 bcik volumio[4531]: info: Discovery: Started advertising with name: Bącik Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "spop"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "outputs"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "albumart"... Oct 12 05:38:05 bcik volumio[4531]: info: Plugin example_plugin is not enabled Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "inputs"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "updater_comm"... Oct 12 05:38:05 bcik volumio[4531]: info: Plugin mpdemulation is not enabled Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "rest_api"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "websocket"... Oct 12 05:38:05 bcik volumio[4531]: info: Starting Socket.io Server version 1.7.4 Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "radio_browser"... Oct 12 05:38:05 bcik volumio[4591]: Forking 3 albumart workers Oct 12 05:38:05 bcik volumio[4531]: info: Loading i18n strings for locale pl Oct 12 05:38:05 bcik volumio[4531]: Updating browse sources language Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::initPlayerControls Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: Express server listening on port 3000 Oct 12 05:38:05 bcik volumio[4531]: [Metrics] WebUI: 1s 290.43ms Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::resetVolumioState Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::getcurrentVolume Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:05 bcik volumio[4531]: info: Volumio Network Manager: Network status updated: 1 Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: Reloading queue from file Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::setRepeat false single undefined Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::setRandom false Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::updateTrackBlock Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrackBlock Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:05 bcik volumio[4531]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 05:38:05 bcik volumio[4531]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 05:38:05 bcik volumio[4531]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 05:38:05 bcik volumio[4531]: info: Setting Device type: Raspberry PI Oct 12 05:38:05 bcik volumio[4531]: info: Completed loading Core Plugins Oct 12 05:38:05 bcik volumio[4531]: info: Preparing to generate the ALSA configuration file Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: Asound.conf file unchanged, so no further update is needed Oct 12 05:38:05 bcik volumio[4531]: info: Output device has changed, restarting MPD Oct 12 05:38:05 bcik volumio[4531]: info: Output device has changed, restarting Shairport Sync Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik sudo[4646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:05 bcik sudo[4648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:05 bcik sudo[4646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4646]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik sudo[4648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik volumio[4531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:05 bcik volumio[4531]: info: ___________ START PLUGINS ___________ Oct 12 05:38:05 bcik volumio[4531]: info: ControllerMpd::onStart: Initializing MPD Oct 12 05:38:05 bcik volumio[4531]: info: Creating MPD Configuration file Oct 12 05:38:05 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285538] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: UPNP Browser: Client initialized successfully Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik sudo[4657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 05:38:05 bcik sudo[4658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:05 bcik sudo[4658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:05 bcik sudo[4660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4658]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik sudo[4657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:05 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:05 bcik volumio[4531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285580] CoreMusicLibrary::Adding element Last_100 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285581] CoreMusicLibrary::Adding element Webradio Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:05 bcik volumio[4531]: info: Initializing BBC Radios Oct 12 05:38:05 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:05 bcik sudo[4657]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:05 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:05 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:05 bcik volumio[4531]: info: Creating Spotify config file Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik sudo[4688]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 05:38:05 bcik sudo[4688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 05:38:05 bcik volumio[4602]: Starting albumart workers Oct 12 05:38:05 bcik volumio[4601]: Starting albumart workers Oct 12 05:38:05 bcik sudo[4688]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285742] CoreMusicLibrary::Adding element Radio Browser Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: Cannot find translation for source Radio Browser Oct 12 05:38:05 bcik volumio[4531]: info: Volumio Calling Home Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: MPD Permissions set Oct 12 05:38:05 bcik volumio[4531]: info: MPD Permissions set Oct 12 05:38:05 bcik volumio[4531]: info: Spotify config file written Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik sudo[4695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 05:38:05 bcik sudo[4695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: No need to fix Spotify hosts Oct 12 05:38:05 bcik volumio[4603]: Starting albumart workers Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:05 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:05 bcik go-librespot[4719]: go-librespot daemon starting... Oct 12 05:38:05 bcik sudo[4695]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik go-librespot[4720]: time="2026-10-12T05:38:05+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:05 bcik go-librespot[4720]: time="2026-10-12T05:38:05+02:00" level=debug msg="app state loaded" Oct 12 05:38:05 bcik go-librespot[4720]: time="2026-10-12T05:38:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:05 bcik volumio[4531]: info: Volumio called home Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:05 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:05 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:05 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:05 bcik sudo[4728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:05 bcik sudo[4728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:05 bcik sudo[4732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:05 bcik sudo[4730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:06 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02: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]" Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02: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]" Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02: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]" Oct 12 05:38:06 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:06 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik systemd[1]: shairport-sync.service: Consumed 1.523s CPU time. Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=info msg="zeroconf server listening on port 43363" Oct 12 05:38:06 bcik volumio[4531]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: Found device Bącik Oct 12 05:38:06 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:06 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:06 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: Found device Bącik Oct 12 05:38:06 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:06 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:06 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:06 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:06 bcik sudo[4732]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik sudo[4728]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:06 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:06 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik sudo[4730]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik volumio[4531]: info: Shairport-Sync Started Oct 12 05:38:06 bcik volumio[4531]: Error adding Membership: Error: addMembership EINVAL Oct 12 05:38:06 bcik volumio[4531]: info: Shairport-Sync Started Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="obtained new client token: AAFTfQKELvtasCX++CCKXCUDeYdo0NZqHYGdeU3JcCCr8Ez9v8ISMTwjH5jUezJ1vlDJhA5RzuZrf1HPtqmRWZUkT7SSl7ISQhAWFG9M9zDQ4y6WjUnzcljs7KGoCKd2goBEQM+KGH8E8dik+uDKwYFFysvlKBnYU1hzaGtrCUuVTutsaVHbbpC6c8xs9iw3kwBSR9yebka+sMqa0MY3Z4Jmhqck110Z+fZFwuxt+72A2cYpG4wK" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: info: Shairport-Sync Started Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="completed challenge" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:06 bcik mpd[4690]: 2026-10-12T05:38:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 05:38:06 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 05:38:06 bcik sudo[4648]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik sudo[4660]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik volumio[4531]: info: Completed starting Core Plugins Oct 12 05:38:06 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:06 bcik volumio[4531]: info: ----- MyVolumio plugins startup ---- Oct 12 05:38:06 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:06 bcik volumio[4531]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 05:38:06 bcik volumio[4531]: error: MPD error: The expression evaluated to a falsy value: Oct 12 05:38:06 bcik volumio[4531]: assert.ok(self.idling) Oct 12 05:38:06 bcik volumio[4531]: error: The expression evaluated to a falsy value: Oct 12 05:38:06 bcik volumio[4531]: assert.ok(self.idling) Oct 12 05:38:06 bcik volumio[4531]: error: updateQueue error: null Oct 12 05:38:06 bcik volumio[4531]: info: MPD running with PID4690 Oct 12 05:38:06 bcik volumio[4531]: ,establishing connection Oct 12 05:38:06 bcik volumio[4531]: error: updateQueue error: null Oct 12 05:38:08 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:08] [connect] Successful connection Oct 12 05:38:08 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791776288 101 Oct 12 05:38:08 bcik volumio[4531]: 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: 3 Oct 12 05:38:08 bcik volumio[4531]: info: go-librespot daemon successfully initialized Oct 12 05:38:09 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4582. Oct 12 05:38:09 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:09 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:09 bcik go-librespot[4767]: go-librespot daemon starting... Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="app state loaded" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02: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]" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02: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]" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02: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]" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="zeroconf server listening on port 42733" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="obtained new client token: AAH2fskJ04hIMyOCRqg48yRx+rhEqo+pR1JUz4jKal33BbnuMiDEA84M6M7fh9LOhZgoZWLfG1XK7+0w/zCWU4FCacBSc0UUy4SQaiBTiQEeal2v9cpkBSVk2noyRv4BF5n7TOi9x9FXtywAsHeCctE4L5hS6bFmddQUyOQbaQe1y58UrsubZNZ5IJpGD4GVgxqPZz+EZgcqVpPI6A1f3J7xBMBr4Cd4yP/L0g8Tr5dvJv3QCEv7uVI=" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="completed challenge" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:09 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:09 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:11 bcik volumio[4531]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 05:38:11 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:11 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:12 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4583. Oct 12 05:38:12 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:12 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:12 bcik go-librespot[4777]: go-librespot daemon starting... Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=debug msg="app state loaded" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02: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]" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02: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]" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02: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]" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=info msg="zeroconf server listening on port 33081" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=debug msg="obtained new client token: AAEAl0y4cuFu/rU8A6UJwGYfcmItqG5IAKjAkO0EbuShg0YTnSem4mTcZEvBmxwIOVeeljqQtazIcjbDPZG9wn7fOFH2wUMJi7QEgdryI/JVKilh412MxElvalgcVzKE8aWD3MnI6FaUVYgggQUebPRSLsdLXdwdkqUCQfE+zwWRp6DlvhSuuJ0SES9njNhoTTZZUxJvkANnCdVUvrGFVYVwVjgGgh9Jw+ggZD1Ei2pmHzsu/WnGEQ0=" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=debug msg="completed challenge" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:13 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:13 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 05:38:14 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:14 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:14 bcik volumio[4531]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 05:38:14 bcik volumio[4531]: info: MyVolumio login type: Token Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 05:38:14 bcik volumio[4531]: info: Streaming services startup Oct 12 05:38:14 bcik volumio[4531]: info: Starting Streaming Daemon Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 05:38:14 bcik sudo[4802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:14 bcik sudo[4802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4802]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik volumio[4531]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:14 bcik volumio[4531]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:14 bcik volumio[4531]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:14 bcik sudo[4809]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:14 bcik sudo[4809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4811]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:14 bcik sudo[4811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4811]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik sudo[4809]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik sudo[4815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 05:38:14 bcik sudo[4815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4815]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik volumio[4531]: info: Upmpdcli Daemon Started Oct 12 05:38:14 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:14 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:15 bcik volumio[4531]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 05:38:15 bcik volumio[4531]: info: MyVolumio token set successfully Oct 12 05:38:15 bcik volumio[4531]: info: MYVOLUMIO: Adding device Oct 12 05:38:15 bcik volumio[4531]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:15 bcik volumio[4531]: info: MyVolumio status changed Oct 12 05:38:15 bcik volumio[4531]: info: Streaming services startup Oct 12 05:38:15 bcik volumio[4531]: info: Starting Streaming Daemon Oct 12 05:38:15 bcik volumio[4531]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 05:38:15 bcik volumio[4531]: info: Removing audio output: Oct 12 05:38:15 bcik volumio[4531]: info: Stoppping Tunnel 1 Oct 12 05:38:15 bcik sudo[4838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:15 bcik sudo[4838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:15 bcik sudo[4840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 05:38:15 bcik sudo[4840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik sudo[4838]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik volumio[4531]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik volumio[4531]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:15 bcik volumio[4531]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:15 bcik sudo[4840]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:15 bcik volumio[4531]: info: Remote SSH Stopped Oct 12 05:38:16 bcik volumio[4531]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:16 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:16 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:16 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:16 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4584. Oct 12 05:38:16 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:16 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:16 bcik go-librespot[4843]: go-librespot daemon starting... Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="app state loaded" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02: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]" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02: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]" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02: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]" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="zeroconf server listening on port 33539" Oct 12 05:38:16 bcik volumio[4531]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="obtained new client token: AAGYSQe05BWTBuyvBttUwyJ25MTnjgoK9CIZfHxGNUPbNlBWVnDrU2UuE/P6Q8wt0YKOVQY1qtAusYLdjAQZEcEhYFNHKkUlII7UkHldCMmtJzDSP/F2T6Bo4szPLZN4YkXjKx1+laf7njQb2kE2nS7UPfr3LOOyG1tQe94nJeXLPcEBiPjsCh3saZwQNm3RYA0hAwgvc5Ms5+DzNHlx3b7htal95kswvwNfcVXtfxyBluv7kkJRyPU=" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="completed challenge" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:16 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:16 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:17 bcik volumio[4531]: info: Updating MyVolumio device info Oct 12 05:38:17 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:17 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:17 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:17 bcik volumio[4531]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:38:17 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:17 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4585. Oct 12 05:38:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:19 bcik go-librespot[4854]: go-librespot daemon starting... Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=debug msg="app state loaded" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02: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]" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02: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]" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02: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]" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=info msg="zeroconf server listening on port 35145" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=debug msg="obtained new client token: AAG5WNuvP7wSYtr8lvvK7sNWjdq4/SL0qM0PUtuOWfO60BkHeDDe6+nk1KAfcEvocdL4HsLTgjr0enhXyyZTTpfOOLEt9mNEOSsZIibmAiityx97Bs7E7joAMB19d5Eb/2h9cZ37Ohoj7qpwQ+J1jtRRJaxqjMR5aqDeFAFpSiC2MxeghJV82iiUiVHBslCB1sCf0GQXQgdrHptNZI5+//xUJ0JM+dg2hZWDM51op3hs7ZYGdiUWrKQ=" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=debug msg="completed challenge" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:20 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:20 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:20 bcik volumio[4531]: info: MYVOLUMIO: Adding device Oct 12 05:38:20 bcik volumio[4531]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:20 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:20 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:20 bcik volumio[4531]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:20 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:20 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:20 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:21 bcik volumio[4531]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:38:21 bcik volumio[4531]: info: Updating MyVolumio device info Oct 12 05:38:21 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:21 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:21 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:22 bcik volumio[4531]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:38:23 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4586. Oct 12 05:38:23 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:23 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:23 bcik go-librespot[4882]: go-librespot daemon starting... Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="app state loaded" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02: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]" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02: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]" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02: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]" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="zeroconf server listening on port 36401" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="obtained new client token: AAG0rIJ32kw+mBj+rpYWMcncBWJoBJqOxcli0Q8l3uCZOM9PmCH5Cb8vNslQ3Z45DM2u/jo+7sRPu4hlEJEy8ZiUyQEulpNInaPKLXPiYup+4/gAVyiAWEYJ9aeoMZEyBcoj/bQfpGK5pIh12mY5cuh+J0oyUcuHBKqUIEcyIuAkqE9MRLo5lKN5nMx1dkgJu0C19Y3iSbiykMj0INzwCwmxBkG8M2jfRhY1rFHiJbLSH4RrCLeoVCw=" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="completed challenge" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:23 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:23 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:23 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:23 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4587. Oct 12 05:38:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:26 bcik go-librespot[4906]: go-librespot daemon starting... Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=debug msg="app state loaded" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02: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]" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02: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]" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02: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]" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=info msg="zeroconf server listening on port 42303" Oct 12 05:38:26 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=debug msg="new websocket client" Oct 12 05:38:26 bcik volumio[4531]: info: Connection to go-librespot Websocket established Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=debug msg="obtained new client token: AAHFjoRMCpq8cqejDFph7m6cwSUiauiLMKEci79TGxT2etRv+Yg1lJQMHcND4DPekS9UApOjV6R+JV0b28+mT7/fXFNTypamCKuFpi8T1uLIUL4Rcl6zr+dyKm4ppr70usyWgLyccg908zYHlWEKmONzKRDjwOZk4yTeepw66gqDy3RlImE1SJS64G3A1eAblDVXMczvE5umEoUG5iOi+53HjhApEWfSdAqZ5+fUsWIpGmT+rOtz1b0=" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=debug msg="completed challenge" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:27 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:27 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:27 bcik volumio[4531]: info: Connection to go-librespot Websocket closed Oct 12 05:38:29 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 05:38:29 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:38:29 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:29 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:29 bcik volumio[4531]: info: Getting Spotify volume Oct 12 05:38:29 bcik volumio[4531]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:29 bcik volumio[4531]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:29 bcik volumio[4531]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 05:38:29 bcik volumio[4531]: errno: -111, Oct 12 05:38:29 bcik volumio[4531]: code: 'ECONNREFUSED', Oct 12 05:38:29 bcik volumio[4531]: syscall: 'connect', Oct 12 05:38:29 bcik volumio[4531]: address: '127.0.0.1', Oct 12 05:38:29 bcik volumio[4531]: port: 9879, Oct 12 05:38:29 bcik volumio[4531]: response: undefined Oct 12 05:38:29 bcik volumio[4531]: } Oct 12 05:38:29 bcik volumio[4531]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:30 bcik sudo[4930]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:37' Oct 12 05:38:30 bcik sudo[4930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:30 bcik sudo[4930]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:30 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 05:38:30 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 05:38:30 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:30.192+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 05:38:30 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:30.193+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:46272->127.0.0.1:3000: read: connection reset by peer" Oct 12 05:38:30 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:30 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4588. Oct 12 05:38:30 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:30 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:30 bcik go-librespot[4935]: go-librespot daemon starting... Oct 12 05:38:30 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 05:38:30 bcik systemd[1]: volumio.service: Consumed 6.346s CPU time. Oct 12 05:38:30 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="app state loaded" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:30 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02: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]" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02: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]" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02: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]" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="zeroconf server listening on port 33613" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="obtained new client token: AAFfWtF5PSFOf8QWBKG/2SrNi3P73S44KzrZdEZ5OUA9+m5lCgXU2ZK3mLevp6GyYdCS2dNtzeNHc628LPNuFdlcW2e9QsGfBadtKROdsaOxiZUBtcuJplUnXsvI/Ulbaigvm0XKUOuqCwByt0yVknWtisFtDV9qd9DhN1bZ54025nAH3bQoLgDjL+usz4aEk1GjsfsI0xYDnEjAuVvwXlrMR6k2j0n0lyGN6vf6GZRtKtOIVlD2+uI=" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="completed challenge" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:30 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21819. Oct 12 05:38:30 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:30 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 05:38:30 bcik systemd[1]: volumio.service: Consumed 6.346s CPU time. Oct 12 05:38:30 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 05:38:30 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:30 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:30 bcik volumio[4960]: info: ----- Volumio3 ---- Oct 12 05:38:30 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:30 bcik volumio[4960]: info: ----- System startup ---- Oct 12 05:38:30 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:31 bcik volumio[4960]: info: MYVOLUMIO Environment detected Oct 12 05:38:31 bcik volumio[4960]: info: Plugin folders cleanup Oct 12 05:38:31 bcik volumio[4960]: info: Scanning into folder /volumio/app/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category audio_interface Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category miscellanea Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category music_service Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category plugins.json Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category system_controller Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category user_interface Oct 12 05:38:31 bcik volumio[4960]: info: Scanning into folder /data/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category music_service Oct 12 05:38:31 bcik volumio[4960]: info: Plugin folders cleanup completed Oct 12 05:38:31 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:31 bcik volumio[4960]: info: ----- Core plugins startup ---- Oct 12 05:38:31 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Adding plugin upnp to MyMusic Plugins Oct 12 05:38:31 bcik volumio[4960]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 05:38:31 bcik volumio[4960]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugins from folder /data/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "system"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "appearance"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "network"... Oct 12 05:38:31 bcik volumio[4960]: info: Refreshing Cached IP Addresses Oct 12 05:38:31 bcik sudo[4990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:31 bcik sudo[4990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:31 bcik sudo[4992]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:31 bcik sudo[4992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:31 bcik sudo[4990]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "services"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "volumio5onboarding"... Oct 12 05:38:31 bcik sudo[4992]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "alsa_controller"... Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "wizard"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "networkfs"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting Udev Watcher for removable devices Oct 12 05:38:31 bcik volumio[4960]: info: Ignoring mount for partition: boot Oct 12 05:38:31 bcik volumio[4960]: info: Ignoring mount for partition: volumio Oct 12 05:38:31 bcik volumio[4960]: info: Ignoring mount for partition: volumio_data Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "volumio_command_line_client"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "upnp"... Oct 12 05:38:31 bcik volumio[4960]: info: [1791776311342] Starting Upmpd Daemon Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "my_music"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "mpd"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "upnp_browser"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting UPNP Browser Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "alarm-clock"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "airplay_emulation"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "last_100"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "webradio"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "i2s_dacs"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "volumiodiscovery"... Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik volumio[4960]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 05:38:31 bcik node[4960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik node[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik node[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik node[4960]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik node[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik node[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik volumio[4960]: info: Discovery: Started advertising with name: Bącik Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "spop"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "outputs"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "albumart"... Oct 12 05:38:31 bcik volumio[4960]: info: Plugin example_plugin is not enabled Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "inputs"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "updater_comm"... Oct 12 05:38:31 bcik volumio[4960]: info: Plugin mpdemulation is not enabled Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "rest_api"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "websocket"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting Socket.io Server version 1.7.4 Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "radio_browser"... Oct 12 05:38:32 bcik volumio[5022]: Forking 3 albumart workers Oct 12 05:38:32 bcik volumio[4960]: info: Loading i18n strings for locale pl Oct 12 05:38:32 bcik volumio[4960]: Updating browse sources language Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::initPlayerControls Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: Express server listening on port 3000 Oct 12 05:38:32 bcik volumio[4960]: [Metrics] WebUI: 1s 272.09ms Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::resetVolumioState Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::getcurrentVolume Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:32 bcik volumio[4960]: info: Volumio Network Manager: Network status updated: 1 Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:32 bcik volumio[4960]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::updateTrackBlock Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrackBlock Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: Reloading queue from file Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::setRepeat false single undefined Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::setRandom false Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 05:38:32 bcik volumio[4960]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 05:38:32 bcik volumio[4960]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:32 bcik volumio[4960]: info: Setting Device type: Raspberry PI Oct 12 05:38:32 bcik volumio[4960]: info: Completed loading Core Plugins Oct 12 05:38:32 bcik volumio[4960]: info: Preparing to generate the ALSA configuration file Oct 12 05:38:32 bcik volumio[4960]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: Asound.conf file unchanged, so no further update is needed Oct 12 05:38:32 bcik volumio[4960]: info: Output device has changed, restarting MPD Oct 12 05:38:32 bcik volumio[4960]: info: Output device has changed, restarting Shairport Sync Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik sudo[5077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:32 bcik sudo[5077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5077]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:32 bcik sudo[5081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:32 bcik volumio[4960]: info: ___________ START PLUGINS ___________ Oct 12 05:38:32 bcik volumio[4960]: info: ControllerMpd::onStart: Initializing MPD Oct 12 05:38:32 bcik volumio[4960]: info: Creating MPD Configuration file Oct 12 05:38:32 bcik sudo[5086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 05:38:32 bcik sudo[5086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312284] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: UPNP Browser: Client initialized successfully Oct 12 05:38:32 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 05:38:32 bcik sudo[5089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:32 bcik sudo[5089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:32 bcik sudo[5092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik sudo[5089]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:32 bcik sudo[5086]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[4960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:32 bcik volumio[4960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312329] CoreMusicLibrary::Adding element Last_100 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312329] CoreMusicLibrary::Adding element Webradio Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:32 bcik volumio[4960]: info: Initializing BBC Radios Oct 12 05:38:32 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:32 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:32 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:32 bcik volumio[4960]: info: Creating Spotify config file Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[5032]: Starting albumart workers Oct 12 05:38:32 bcik sudo[5119]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 05:38:32 bcik sudo[5119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 05:38:32 bcik volumio[5034]: Starting albumart workers Oct 12 05:38:32 bcik sudo[5119]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[5033]: Starting albumart workers Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312454] CoreMusicLibrary::Adding element Radio Browser Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: Cannot find translation for source Radio Browser Oct 12 05:38:32 bcik volumio[4960]: info: Volumio Calling Home Oct 12 05:38:32 bcik volumio[4960]: info: MPD Permissions set Oct 12 05:38:32 bcik volumio[4960]: info: MPD Permissions set Oct 12 05:38:32 bcik volumio[4960]: info: Spotify config file written Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 12 05:38:32 bcik sudo[5137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 05:38:32 bcik volumio[4960]: info: Volumio called home Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik sudo[5137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: No need to fix Spotify hosts Oct 12 05:38:32 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:32 bcik go-librespot[5145]: go-librespot daemon starting... Oct 12 05:38:32 bcik sudo[5137]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="app state loaded" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:32 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:32 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:32 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:32 bcik sudo[5167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:32 bcik sudo[5167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:32 bcik sudo[5170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:32 bcik sudo[5171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: Found device Bącik Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: Found device Bącik Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02: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]" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02: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]" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02: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]" Oct 12 05:38:32 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:32 bcik systemd[1]: shairport-sync.service: Consumed 1.507s CPU time. Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="zeroconf server listening on port 37093" Oct 12 05:38:32 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:32 bcik sudo[5170]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5167]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5171]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[4960]: info: Shairport-Sync Started Oct 12 05:38:32 bcik volumio[4960]: Error adding Membership: Error: addMembership EINVAL Oct 12 05:38:32 bcik volumio[4960]: info: Shairport-Sync Started Oct 12 05:38:32 bcik volumio[4960]: info: Shairport-Sync Started Oct 12 05:38:32 bcik volumio[4960]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="obtained new client token: AAEhBnUCREmJMA5kGr9OXRU+RbO0DUPDKI+j+6+39AuvzyglNIUtr9XJ4eadyDU6cgbD7HMYn2CVY7id08FOhR7rcTqBN7vjqxErHyvKhJV5j7momuS9LIIXh07gkuzDIYmOA1Vr0l59TYf/Xip7+VWDM+21Hs4X4nSsQcvmFYhRVH38sE/Eq95aUke1l4GSmSklVfEyAazzfG2KIWqka/zBiNCq9TOHcKU3+pZ2tN7VyvX9uiCG1vY=" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="completed challenge" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:32 bcik mpd[5121]: 2026-10-12T05:38:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 05:38:32 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 05:38:32 bcik sudo[5092]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5081]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[4960]: info: Completed starting Core Plugins Oct 12 05:38:32 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:32 bcik volumio[4960]: info: ----- MyVolumio plugins startup ---- Oct 12 05:38:32 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:32 bcik volumio[4960]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 05:38:32 bcik volumio[4960]: error: MPD error: The expression evaluated to a falsy value: Oct 12 05:38:32 bcik volumio[4960]: assert.ok(self.idling) Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:32 bcik volumio[4960]: error: The expression evaluated to a falsy value: Oct 12 05:38:32 bcik volumio[4960]: assert.ok(self.idling) Oct 12 05:38:32 bcik volumio[4960]: info: MPD running with PID5121 Oct 12 05:38:32 bcik volumio[4960]: ,establishing connection Oct 12 05:38:32 bcik volumio[4960]: error: updateQueue error: null Oct 12 05:38:32 bcik volumio[4960]: error: updateQueue error: null Oct 12 05:38:32 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:32 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:35 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:35] [connect] Successful connection Oct 12 05:38:35 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791776315 101 Oct 12 05:38:35 bcik volumio[4960]: 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: 3 Oct 12 05:38:35 bcik volumio[4960]: info: go-librespot daemon successfully initialized Oct 12 05:38:36 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4589. Oct 12 05:38:36 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:36 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:36 bcik go-librespot[5197]: go-librespot daemon starting... Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="app state loaded" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02: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]" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02: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]" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02: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]" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="zeroconf server listening on port 35397" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="obtained new client token: AAFfJFnb5Nv53nOE4rjVXTh8E7k2T1aXHjdnBTYurQQ5u2aWm3M/Z7K5pjG/BQcW92bH4/0Mg7DcUhDxqC02+KOBx2dGQg/RchKgdgFv8i5FsUh2XPxAVm815gopyBbH2s6MvaHM/Za8gvfj6L88Im36ef6BebzlFVjHg9ALO8/S35/tWzBLPdUTqeglUSi3aEVGUFzzCTt+93Ct4w2rk08JtBPblPOU+fTO9L71lbuDuLu+vhQx" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="completed challenge" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:36 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:36 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:37 bcik volumio[4960]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 05:38:38 bcik volumio[4960]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:38 bcik volumio[4960]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:39 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4590. Oct 12 05:38:39 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:39 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:39 bcik go-librespot[5208]: go-librespot daemon starting... Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="app state loaded" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02: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]" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02: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]" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02: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]" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="zeroconf server listening on port 38581" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="obtained new client token: AAEbiQtUo4ClEhLr7YzM33UPnkhN9SMTmrahwL84J31an1ixJ18n0hjp+X8XPs72/vIvOVbmJrRT/QP+chXSgh0gkQjuFkyJufjzDwNvgfgz3VJTIy+pvcgpB/2KdDjpE+C8UcXhLs1vlZzENfRbMCtVGK/w3RnkGytldvIuQp8T802tYPHziD78+XxTVJmOuRFDxxWHRTpVU/LpMtuAKdigKVAZOsHVC0s4koI/icR432p/9YRnEG8=" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="completed challenge" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:39 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:39 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 05:38:41 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:41 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:41 bcik volumio[4960]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 05:38:41 bcik volumio[4960]: info: MyVolumio login type: Token Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 05:38:41 bcik volumio[4960]: info: Streaming services startup Oct 12 05:38:41 bcik volumio[4960]: info: Starting Streaming Daemon Oct 12 05:38:41 bcik sudo[5233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:41 bcik sudo[5233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 05:38:41 bcik sudo[5233]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik sudo[5240]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:41 bcik sudo[5240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik sudo[5240]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik sudo[5242]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:41 bcik sudo[5242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik sudo[5242]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik volumio[4960]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:41 bcik volumio[4960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:41 bcik volumio[4960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:41 bcik sudo[5246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 05:38:41 bcik sudo[5246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik sudo[5246]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik volumio[4960]: info: Upmpdcli Daemon Started Oct 12 05:38:41 bcik volumio[4960]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:41 bcik volumio[4960]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:42 bcik volumio[4960]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 05:38:42 bcik volumio[4960]: info: MyVolumio token set successfully Oct 12 05:38:42 bcik volumio[4960]: info: MYVOLUMIO: Adding device Oct 12 05:38:42 bcik volumio[4960]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:42 bcik volumio[4960]: info: MyVolumio status changed Oct 12 05:38:42 bcik volumio[4960]: info: Streaming services startup Oct 12 05:38:42 bcik volumio[4960]: info: Starting Streaming Daemon Oct 12 05:38:42 bcik volumio[4960]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 05:38:42 bcik volumio[4960]: info: Removing audio output: Oct 12 05:38:42 bcik volumio[4960]: info: Stoppping Tunnel 1 Oct 12 05:38:42 bcik sudo[5270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:42 bcik sudo[5270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:42 bcik sudo[5272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 05:38:42 bcik sudo[5272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik sudo[5270]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:42 bcik volumio[4960]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik volumio[4960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:42 bcik volumio[4960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik sudo[5272]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:42 bcik volumio[4960]: info: Remote SSH Stopped Oct 12 05:38:42 bcik volumio[4960]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:42 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:42 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:42 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:43 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4591. Oct 12 05:38:43 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:43 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:43 bcik go-librespot[5275]: go-librespot daemon starting... Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=debug msg="app state loaded" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02: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]" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02: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]" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02: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]" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=info msg="zeroconf server listening on port 35877" Oct 12 05:38:43 bcik volumio[4960]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:38:43 bcik volumio[4960]: info: Updating MyVolumio device info Oct 12 05:38:43 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:43 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:43 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:44 bcik volumio[4960]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:38:44 bcik volumio[4960]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:44 bcik go-librespot[5276]: time="2026-10-12T05:38:44+02:00" level=debug msg="new websocket client" Oct 12 05:38:44 bcik volumio[4960]: info: Connection to go-librespot Websocket established Oct 12 05:38:47 bcik volumio[4960]: info: MYVOLUMIO: Adding device Oct 12 05:38:47 bcik volumio[4960]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:47 bcik volumio[4960]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:47 bcik volumio[4960]: info: Getting Spotify volume Oct 12 05:38:47 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:47 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:47 bcik volumio[4960]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Oct 12 05:38:47 bcik volumio[4960]: SPOTIFY: SPOTIFY VOLUME undefined Oct 12 05:38:47 bcik volumio[4960]: SPOTIFY: VOLUMIO VOLUME 41 Oct 12 05:38:47 bcik volumio[4960]: info: Aligning Spotify Volume to Volumio Volume Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:47 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:47 bcik volumio[4960]: info: Setting Spotify Volume from Volumio: 41 Oct 12 05:38:47 bcik go-librespot[5276]: time="2026-10-12T05:38:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: invalid status code from clienttoken: 503" Oct 12 05:38:47 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:47 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:47 bcik volumio[4960]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:47 bcik volumio[4960]: Error: socket hang up Oct 12 05:38:47 bcik volumio[4960]: at connResetException (node:internal/errors:720:14) Oct 12 05:38:47 bcik volumio[4960]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 12 05:38:47 bcik volumio[4960]: at Socket.emit (node:events:526:35) Oct 12 05:38:47 bcik volumio[4960]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 12 05:38:47 bcik volumio[4960]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 12 05:38:47 bcik volumio[4960]: code: 'ECONNRESET', Oct 12 05:38:47 bcik volumio[4960]: response: undefined Oct 12 05:38:47 bcik volumio[4960]: } Oct 12 05:38:47 bcik volumio[4960]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:47 bcik sudo[5317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:37' Oct 12 05:38:47 bcik sudo[5317]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"