Aug 31 18:42:00 bcik volumio[9645]: info: Updating MyVolumio device info Aug 31 18:42:00 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:00 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:00 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:00 bcik volumio[9645]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 18:42:00 bcik volumio[9645]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:00 bcik volumio[9645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:03 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Aug 31 18:42:03 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:03 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:03 bcik go-librespot[9992]: go-librespot daemon starting... Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=debug msg="app state loaded" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+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]" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+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]" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=info msg="zeroconf server listening on port 40713" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=debug msg="obtained new client token: AAEQiGulYnM+85CXJVr9ee1aIsAonk7D5jkjIvyNee5dLjzw2mbeuRaHhP/Z4lDWLj5bidvc/6Y1neBiUIzn2GqmUhBArn1NE5D3AMT5/CsFqYBpGQaMsKDjwAL2N0szN5NUi3O3VZ+dQEt7T8WQJjkEK/x+XiaOWijsLgT1eQ48uJTBh14fMZr8kX/zGyTDKHdD0cwFTL0MzCI98QXuVqblDsGXz9EDlYtKKXS+Psbi2bYcnHk1" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=debug msg="completed challenge" Aug 31 18:42:03 bcik volumio[9645]: info: MYVOLUMIO: Adding device Aug 31 18:42:03 bcik volumio[9645]: info: MYVOLUMIO: Evaluating Server Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:03 bcik go-librespot[9993]: time="2026-08-31T18:42:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:03 bcik volumio[9645]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:03 bcik volumio[9645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:03 bcik volumio[9645]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 18:42:03 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:03 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:03 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:04 bcik volumio[9645]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 18:42:04 bcik volumio[9645]: info: Updating MyVolumio device info Aug 31 18:42:04 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:04 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:04 bcik volumio[9645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:05 bcik volumio[9645]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 18:42:06 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Aug 31 18:42:06 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:06 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:06 bcik go-librespot[10021]: go-librespot daemon starting... Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=debug msg="app state loaded" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+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]" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+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]" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=info msg="zeroconf server listening on port 39483" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=debug msg="obtained new client token: AAGJk2+/KCwV83Wiw077TiF2DHdT4AyrAq7GuFFcNM7JEvuOSXzPofCcdumfUqRCrnDM5/XQ5f4k2L5LCBWHLMzmftnggsvpHwduuVjT6ZkJGq2uE0M4gPlXNxyudjSQ2Nwos3+eo1k786q89+CQmWdg4SU0yPlN0Wx8twzcwHKmBX667XIDoVKiAs9W9kWT8UhtrIKDEat1UJuucra0hnzXaQtJhgoZxwV7n35LahXtuYoCJk4NaJE=" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:06 bcik volumio[9645]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=debug msg="new websocket client" Aug 31 18:42:06 bcik volumio[9645]: info: Connection to go-librespot Websocket established Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=debug msg="completed challenge" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:06 bcik go-librespot[10022]: time="2026-08-31T18:42:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:06 bcik volumio[9645]: info: Connection to go-librespot Websocket closed Aug 31 18:42:09 bcik volumio[9645]: info: Getting Spotify volume Aug 31 18:42:09 bcik volumio[9645]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:42:09 bcik volumio[9645]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:09 bcik volumio[9645]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 18:42:09 bcik volumio[9645]: errno: -111, Aug 31 18:42:09 bcik volumio[9645]: code: 'ECONNREFUSED', Aug 31 18:42:09 bcik volumio[9645]: syscall: 'connect', Aug 31 18:42:09 bcik volumio[9645]: address: '127.0.0.1', Aug 31 18:42:09 bcik volumio[9645]: port: 9879, Aug 31 18:42:09 bcik volumio[9645]: response: undefined Aug 31 18:42:09 bcik volumio[9645]: } Aug 31 18:42:09 bcik volumio[9645]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:42:09 bcik sudo[10059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 18:41' Aug 31 18:42:09 bcik sudo[10059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:09 bcik sudo[10059]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:09 bcik volumio-remote-updater[962]: [2026-08-31 18:42:09] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 18:42:09 bcik volumio-remote-updater[962]: [2026-08-31 18:42:09] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 18:42:09 bcik volumio5-onboarding[6890]: time=2026-08-31T18:42:09.983+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 18:42:09 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:09 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Aug 31 18:42:09 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:09 bcik volumio5-onboarding[6890]: time=2026-08-31T18:42:09.989+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 18:42:10 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:10 bcik go-librespot[10064]: go-librespot daemon starting... Aug 31 18:42:10 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 18:42:10 bcik systemd[1]: volumio.service: Consumed 6.147s CPU time. Aug 31 18:42:10 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+02:00" level=debug msg="app state loaded" Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:10 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+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]" Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+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]" Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+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]" Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+02:00" level=info msg="zeroconf server listening on port 33729" Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+02:00" level=debug msg="obtained new client token: AAEP7S6iiLJY5GXO9NUhSUyYJYoVBSYkAWR8o4up5WW8JAKhg7VUasjgAugIoFjhCcGVVYgRjMtNS3f0NlTcFbiiSAmLmqVUrGP04xGJSRxzmjY+RfQ0P64hABQ5Yq4eV/l99z6yjMyCkC4XKT3nTOrfLvg78Sc5pJ4C0SEtCALmHbdQ7CMqV58LuMD1EfyOAO4YpwMcJlW5EbhpFPH8+yBtl2d7X+prcMP24mlegZsZLvA2oMqk" Aug 31 18:42:10 bcik go-librespot[10065]: time="2026-08-31T18:42:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:10 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 407. Aug 31 18:42:10 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 18:42:10 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 18:42:10 bcik systemd[1]: volumio.service: Consumed 6.147s CPU time. Aug 31 18:42:10 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 18:42:10 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 18:42:10 bcik volumio[10081]: info: ------------------------------------------- Aug 31 18:42:10 bcik volumio[10081]: info: ----- Volumio3 ---- Aug 31 18:42:10 bcik volumio[10081]: info: ------------------------------------------- Aug 31 18:42:10 bcik volumio[10081]: info: ----- System startup ---- Aug 31 18:42:10 bcik volumio[10081]: info: ------------------------------------------- Aug 31 18:42:10 bcik volumio[10081]: info: MYVOLUMIO Environment detected Aug 31 18:42:10 bcik volumio[10081]: info: Plugin folders cleanup Aug 31 18:42:10 bcik volumio[10081]: info: Scanning into folder /volumio/app/plugins/ Aug 31 18:42:10 bcik volumio[10081]: info: Scanning category audio_interface Aug 31 18:42:10 bcik volumio[10081]: info: Scanning category miscellanea Aug 31 18:42:10 bcik volumio[10081]: info: Scanning category music_service Aug 31 18:42:10 bcik volumio[10081]: info: Scanning category plugins.json Aug 31 18:42:10 bcik volumio[10081]: info: Scanning category system_controller Aug 31 18:42:10 bcik volumio[10081]: info: Scanning category user_interface Aug 31 18:42:10 bcik volumio[10081]: info: Scanning into folder /data/plugins/ Aug 31 18:42:10 bcik volumio[10081]: info: Scanning category music_service Aug 31 18:42:10 bcik volumio[10081]: info: Plugin folders cleanup completed Aug 31 18:42:10 bcik volumio[10081]: info: ------------------------------------------- Aug 31 18:42:10 bcik volumio[10081]: info: ----- Core plugins startup ---- Aug 31 18:42:10 bcik volumio[10081]: info: ------------------------------------------- Aug 31 18:42:10 bcik volumio[10081]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 18:42:10 bcik volumio[10081]: info: Adding plugin upnp to MyMusic Plugins Aug 31 18:42:10 bcik volumio[10081]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 18:42:10 bcik volumio[10081]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 18:42:10 bcik volumio[10081]: info: Loading plugins from folder /data/plugins/ Aug 31 18:42:10 bcik volumio[10081]: info: Loading plugin "system"... Aug 31 18:42:10 bcik volumio[10081]: info: Loading plugin "appearance"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "network"... Aug 31 18:42:11 bcik volumio[10081]: info: Refreshing Cached IP Addresses Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "services"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "volumio5onboarding"... Aug 31 18:42:11 bcik sudo[10112]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 18:42:11 bcik sudo[10112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:11 bcik sudo[10110]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 18:42:11 bcik sudo[10110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "alsa_controller"... Aug 31 18:42:11 bcik sudo[10110]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:11 bcik sudo[10112]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "wizard"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "networkfs"... Aug 31 18:42:11 bcik volumio[10081]: info: Starting Udev Watcher for removable devices Aug 31 18:42:11 bcik volumio[10081]: info: Ignoring mount for partition: boot Aug 31 18:42:11 bcik volumio[10081]: info: Ignoring mount for partition: volumio Aug 31 18:42:11 bcik volumio[10081]: info: Ignoring mount for partition: volumio_data Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "volumio_command_line_client"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "upnp"... Aug 31 18:42:11 bcik volumio[10081]: info: [1788194531080] Starting Upmpd Daemon Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "my_music"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "mpd"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "upnp_browser"... Aug 31 18:42:11 bcik volumio[10081]: info: Starting UPNP Browser Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "alarm-clock"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "airplay_emulation"... Aug 31 18:42:11 bcik volumio[10081]: info: Starting Shairport Sync Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "last_100"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "webradio"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "i2s_dacs"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "volumiodiscovery"... Aug 31 18:42:11 bcik volumio[10081]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 18:42:11 bcik volumio[10081]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:42:11 bcik volumio[10081]: *** WARNING *** For more information see Aug 31 18:42:11 bcik volumio[10081]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 18:42:11 bcik volumio[10081]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:42:11 bcik volumio[10081]: *** WARNING *** For more information see Aug 31 18:42:11 bcik node[10081]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 18:42:11 bcik node[10081]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:42:11 bcik node[10081]: *** WARNING *** For more information see Aug 31 18:42:11 bcik node[10081]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 18:42:11 bcik node[10081]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 18:42:11 bcik node[10081]: *** WARNING *** For more information see Aug 31 18:42:11 bcik volumio[10081]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 18:42:11 bcik volumio[10081]: info: Discovery: Started advertising with name: Bącik Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "spop"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "outputs"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "albumart"... Aug 31 18:42:11 bcik volumio[10081]: info: Plugin example_plugin is not enabled Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "inputs"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "updater_comm"... Aug 31 18:42:11 bcik volumio[10081]: info: Plugin mpdemulation is not enabled Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "rest_api"... Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "websocket"... Aug 31 18:42:11 bcik volumio[10081]: info: Starting Socket.io Server version 1.7.4 Aug 31 18:42:11 bcik volumio[10081]: info: Loading plugin "radio_browser"... Aug 31 18:42:11 bcik volumio[10142]: Forking 3 albumart workers Aug 31 18:42:11 bcik volumio[10081]: info: Loading i18n strings for locale pl Aug 31 18:42:11 bcik volumio[10081]: Updating browse sources language Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::initPlayerControls Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: Express server listening on port 3000 Aug 31 18:42:11 bcik volumio[10081]: [Metrics] WebUI: 1s 294.27ms Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::resetVolumioState Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::getcurrentVolume Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 18:42:11 bcik volumio[10081]: info: Volumio Network Manager: Network status updated: 1 Aug 31 18:42:11 bcik volumio[10081]: 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 Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: Reloading queue from file Aug 31 18:42:11 bcik volumio[10081]: 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 Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::setRepeat false single undefined Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::pushState Aug 31 18:42:11 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::volumioPushState Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::setRandom false Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::pushState Aug 31 18:42:11 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::volumioPushState Aug 31 18:42:11 bcik volumio[10081]: info: VolumeController:: Volume=53 Mute =false Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::pushState Aug 31 18:42:11 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::volumioPushState Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::updateTrackBlock Aug 31 18:42:11 bcik volumio[10081]: info: CorePlayQueue::getTrackBlock Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 18:42:11 bcik volumio[10081]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 18:42:11 bcik volumio[10081]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 18:42:11 bcik volumio[10081]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 18:42:11 bcik volumio[10081]: 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 Aug 31 18:42:11 bcik volumio[10081]: info: Setting Device type: Raspberry PI Aug 31 18:42:11 bcik volumio[10081]: info: Completed loading Core Plugins Aug 31 18:42:11 bcik volumio[10081]: info: Preparing to generate the ALSA configuration file Aug 31 18:42:11 bcik volumio[10081]: 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 Aug 31 18:42:11 bcik volumio[10081]: 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 Aug 31 18:42:11 bcik volumio[10081]: info: VolumeController:: Volume=53 Mute =false Aug 31 18:42:11 bcik volumio[10081]: info: CoreStateMachine::pushState Aug 31 18:42:11 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::volumioPushState Aug 31 18:42:11 bcik volumio[10081]: info: Asound.conf file unchanged, so no further update is needed Aug 31 18:42:11 bcik volumio[10081]: info: Output device has changed, restarting MPD Aug 31 18:42:11 bcik volumio[10081]: info: Output device has changed, restarting Shairport Sync Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:11 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:11 bcik sudo[10197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 18:42:11 bcik sudo[10197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:11 bcik sudo[10197]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:11 bcik volumio[10081]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 18:42:11 bcik volumio[10081]: info: ___________ START PLUGINS ___________ Aug 31 18:42:12 bcik sudo[10201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 18:42:12 bcik sudo[10201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik volumio[10081]: info: ControllerMpd::onStart: Initializing MPD Aug 31 18:42:12 bcik volumio[10081]: info: Creating MPD Configuration file Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 18:42:12 bcik volumio[10081]: info: [1788194532011] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:42:12 bcik sudo[10207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 18:42:12 bcik sudo[10207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik volumio[10081]: info: UPNP Browser: Client initialized successfully Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:12 bcik sudo[10210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 18:42:12 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 18:42:12 bcik sudo[10210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik sudo[10207]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik volumio[10081]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:12 bcik sudo[10217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 18:42:12 bcik sudo[10217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik sudo[10217]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 18:42:12 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 18:42:12 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 18:42:12 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 18:42:12 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 18:42:12 bcik volumio[10081]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 18:42:12 bcik volumio[10081]: info: [1788194532054] CoreMusicLibrary::Adding element Last_100 Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 18:42:12 bcik volumio[10081]: info: [1788194532055] CoreMusicLibrary::Adding element Webradio Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:42:12 bcik volumio[10081]: info: Initializing BBC Radios Aug 31 18:42:12 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 18:42:12 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: Creating Spotify config file Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik sudo[10237]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 18:42:12 bcik sudo[10237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 18:42:12 bcik sudo[10237]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik volumio[10152]: Starting albumart workers Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 18:42:12 bcik volumio[10081]: info: [1788194532164] CoreMusicLibrary::Adding element Radio Browser Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:42:12 bcik volumio[10081]: Cannot find translation for source Radio Browser Aug 31 18:42:12 bcik volumio[10081]: info: Volumio Calling Home Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10154]: Starting albumart workers Aug 31 18:42:12 bcik volumio[10153]: Starting albumart workers Aug 31 18:42:12 bcik volumio[10081]: info: MPD Permissions set Aug 31 18:42:12 bcik volumio[10081]: info: MPD Permissions set Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: info: Spotify config file written Aug 31 18:42:12 bcik volumio[10081]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 18:42:12 bcik sudo[10244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 18:42:12 bcik sudo[10244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 31 18:42:12 bcik systemd[1]: go-librespot-daemon.service: Killing process 10069 (go-librespot) with signal SIGKILL. Aug 31 18:42:12 bcik systemd[1]: go-librespot-daemon.service: Killing process 10072 (go-librespot) with signal SIGKILL. Aug 31 18:42:12 bcik systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 31 18:42:12 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:12 bcik volumio[10081]: info: No need to fix Spotify hosts Aug 31 18:42:12 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:12 bcik go-librespot[10251]: go-librespot daemon starting... Aug 31 18:42:12 bcik sudo[10244]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=debug msg="app state loaded" Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:12 bcik volumio[10081]: info: Volumio called home Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: info: Starting Shairport Sync Aug 31 18:42:12 bcik volumio[10081]: info: Starting Shairport Sync Aug 31 18:42:12 bcik volumio[10081]: info: Starting Shairport Sync Aug 31 18:42:12 bcik sudo[10266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 18:42:12 bcik sudo[10266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik sudo[10269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 18:42:12 bcik sudo[10269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik sudo[10264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 18:42:12 bcik sudo[10264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:12 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 18:42:12 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 18:42:12 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:42:12 bcik systemd[1]: shairport-sync.service: Consumed 1.536s CPU time. Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+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]" Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+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]" Aug 31 18:42:12 bcik volumio[10081]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 18:42:12 bcik volumio[10081]: info: Discovery: Found device Bącik Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::volumioGetState Aug 31 18:42:12 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=info msg="zeroconf server listening on port 33571" Aug 31 18:42:12 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:42:12 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 18:42:12 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 18:42:12 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:42:12 bcik sudo[10266]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 18:42:12 bcik volumio[10081]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 18:42:12 bcik sudo[10269]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik sudo[10264]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 18:42:12 bcik volumio[10081]: info: Discovery: Found device Bącik Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::volumioGetState Aug 31 18:42:12 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:12 bcik volumio[10081]: info: CoreCommandRouter::volumioGetState Aug 31 18:42:12 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:12 bcik volumio[10081]: info: Shairport-Sync Started Aug 31 18:42:12 bcik volumio[10081]: Error adding Membership: Error: addMembership EINVAL Aug 31 18:42:12 bcik volumio[10081]: info: Shairport-Sync Started Aug 31 18:42:12 bcik volumio[10081]: info: Shairport-Sync Started Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=debug msg="obtained new client token: AAF/enwg+88WGXFVAm0EqrOi90VKzAEGwYzhiBUJiN8h/GNa9LkGpvvNTtjTZfXTN+sot5fxCY7CRxyVi+y77AZgUIxc019F2z4lmWU8ettqwHLfsyW+YBAowmxQ4mqt0Pc/YvPS1UOnwrm6rJI6iyW2v8GjbkwqemZuQQJHZx9etiJtRCR7SNs5vKVscYpDDkSwpHQOvxZXVFn85GxrpGV25MB0otWNb7QdTbUgFD5AYqe9+F0ruj0=" Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=debug msg="completed challenge" Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik go-librespot[10257]: time="2026-08-31T18:42:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:12 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik mpd[10239]: 2026-08-31T18:42:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 18:42:12 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 18:42:12 bcik sudo[10210]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik sudo[10201]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: info: Completed starting Core Plugins Aug 31 18:42:12 bcik volumio[10081]: info: ------------------------------------------- Aug 31 18:42:12 bcik volumio[10081]: info: ----- MyVolumio plugins startup ---- Aug 31 18:42:12 bcik volumio[10081]: info: ------------------------------------------- Aug 31 18:42:12 bcik volumio[10081]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: info: MPD running with PID10239 Aug 31 18:42:12 bcik volumio[10081]: ,establishing connection Aug 31 18:42:12 bcik volumio[10081]: error: MPD error: The expression evaluated to a falsy value: Aug 31 18:42:12 bcik volumio[10081]: assert.ok(self.idling) Aug 31 18:42:12 bcik volumio[10081]: error: The expression evaluated to a falsy value: Aug 31 18:42:12 bcik volumio[10081]: assert.ok(self.idling) Aug 31 18:42:12 bcik volumio[10081]: error: MPD error: The expression evaluated to a falsy value: Aug 31 18:42:12 bcik volumio[10081]: assert.ok(self.idling) Aug 31 18:42:12 bcik volumio[10081]: error: The expression evaluated to a falsy value: Aug 31 18:42:12 bcik volumio[10081]: assert.ok(self.idling) Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: error: updateQueue error: null Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:12 bcik volumio[10081]: 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 Aug 31 18:42:14 bcik volumio-remote-updater[962]: [2026-08-31 18:42:14] [connect] Successful connection Aug 31 18:42:14 bcik volumio-remote-updater[962]: [2026-08-31 18:42:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788194534 101 Aug 31 18:42:14 bcik volumio[10081]: 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 Aug 31 18:42:15 bcik volumio[10081]: info: go-librespot daemon successfully initialized Aug 31 18:42:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 31 18:42:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:15 bcik go-librespot[10317]: go-librespot daemon starting... Aug 31 18:42:15 bcik go-librespot[10318]: time="2026-08-31T18:42:15+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:15 bcik go-librespot[10318]: time="2026-08-31T18:42:15+02:00" level=debug msg="app state loaded" Aug 31 18:42:15 bcik go-librespot[10318]: time="2026-08-31T18:42:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:15 bcik go-librespot[10318]: time="2026-08-31T18:42: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 18:42:15 bcik go-librespot[10318]: time="2026-08-31T18:42:15+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]" Aug 31 18:42:15 bcik go-librespot[10318]: time="2026-08-31T18:42:15+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]" Aug 31 18:42:15 bcik go-librespot[10318]: time="2026-08-31T18:42:15+02:00" level=info msg="zeroconf server listening on port 34675" Aug 31 18:42:16 bcik go-librespot[10318]: time="2026-08-31T18:42:16+02:00" level=debug msg="obtained new client token: AAH/msJOvQJEZ5jJmGp6TdQVO8NM+oRlsPp30+yhlQAdNO+7W7aPyJFIwQ1Ato5E6lhYpPz6Nz0ESXqLEwz6gJTEGzSAmcOSjaC6P1+MtxUGWny8+AT7Ww6fM55GwtRPGJFyfCrt0i1wbuh//tErxcsh8W77LpQf9O98uHdy3exG6Yq2qpoVbVRNfRMrofZHXaIExPIciCUZI9MWJ7Obk8MDI4ZW8Wt0nt0akt0Da3+kInVDOho9Mpc=" Aug 31 18:42:16 bcik go-librespot[10318]: time="2026-08-31T18:42:16+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" Aug 31 18:42:16 bcik go-librespot[10318]: time="2026-08-31T18:42:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 18:42:16 bcik go-librespot[10318]: time="2026-08-31T18:42:16+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:16 bcik go-librespot[10318]: time="2026-08-31T18:42:16+02:00" level=debug msg="completed challenge" Aug 31 18:42:16 bcik go-librespot[10318]: time="2026-08-31T18:42:16+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:16 bcik go-librespot[10318]: time="2026-08-31T18:42:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:16 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:16 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:17 bcik volumio[10081]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 18:42:18 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:18 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 31 18:42:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:19 bcik go-librespot[10327]: go-librespot daemon starting... Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=debug msg="app state loaded" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42: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]" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42: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]" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42: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]" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=info msg="zeroconf server listening on port 45333" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=debug msg="obtained new client token: AAFEYPGeXT2oeBn3nlKTw0E0htKMBvysLYD0uKOi3CPaDQyEZ+gqByoeAOcIbDpLYGdNV1ZL0kvwhPaIA/lwM3IANJjLNPF6PCu32XwJk1I9sHyRf/+8wcEoiHf+mPLp29PKwHQ/96EuCMtGs8TyrFyWX92YjJOOtIY1tlEX2WbNs5Rn11/YRU433Nw/8GkKF+qQYumdnUtSf4tPo8cbrX/M15+GayLVxxhMU1y4oqykVl8Z1f6z4kw=" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=debug msg="completed challenge" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:19 bcik go-librespot[10328]: time="2026-08-31T18:42:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:19 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:19 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 18:42:20 bcik volumio[10081]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 18:42:20 bcik volumio[10081]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 18:42:20 bcik volumio[10081]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 18:42:20 bcik volumio[10081]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 18:42:20 bcik volumio[10081]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 18:42:20 bcik volumio[10081]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 18:42:20 bcik volumio[10081]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 18:42:20 bcik volumio[10081]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 18:42:21 bcik volumio[10081]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 18:42:21 bcik volumio[10081]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 18:42:21 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:21 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:21 bcik volumio[10081]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 18:42:21 bcik volumio[10081]: info: MyVolumio login type: Token Aug 31 18:42:21 bcik volumio[10081]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 18:42:21 bcik volumio[10081]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 18:42:21 bcik volumio[10081]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 18:42:21 bcik volumio[10081]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 18:42:21 bcik volumio[10081]: info: Streaming services startup Aug 31 18:42:21 bcik volumio[10081]: info: Starting Streaming Daemon Aug 31 18:42:21 bcik sudo[10352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 18:42:21 bcik sudo[10352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:21 bcik volumio[10081]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 18:42:21 bcik sudo[10352]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:21 bcik sudo[10359]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 18:42:21 bcik sudo[10359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:21 bcik sudo[10361]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 18:42:21 bcik sudo[10361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:21 bcik sudo[10359]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:21 bcik sudo[10361]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:21 bcik volumio[10081]: error: Cannot start Volumio Streaming Daemon Aug 31 18:42:21 bcik volumio[10081]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 18:42:21 bcik volumio[10081]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 18:42:21 bcik sudo[10365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 18:42:21 bcik sudo[10365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:21 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:21 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:21 bcik sudo[10365]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:21 bcik volumio[10081]: info: Upmpdcli Daemon Started Aug 31 18:42:21 bcik volumio[10081]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 18:42:22 bcik volumio[10081]: info: MyVolumio token set successfully Aug 31 18:42:22 bcik volumio[10081]: info: MYVOLUMIO: Adding device Aug 31 18:42:22 bcik volumio[10081]: info: MYVOLUMIO: Evaluating Server Aug 31 18:42:22 bcik volumio[10081]: info: MyVolumio status changed Aug 31 18:42:22 bcik volumio[10081]: info: Streaming services startup Aug 31 18:42:22 bcik volumio[10081]: info: Starting Streaming Daemon Aug 31 18:42:22 bcik volumio[10081]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 18:42:22 bcik volumio[10081]: info: Removing audio output: Aug 31 18:42:22 bcik volumio[10081]: info: Stoppping Tunnel 1 Aug 31 18:42:22 bcik sudo[10388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 18:42:22 bcik sudo[10388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 31 18:42:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:22 bcik sudo[10392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 18:42:22 bcik sudo[10392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 18:42:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:22 bcik sudo[10388]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:22 bcik go-librespot[10390]: go-librespot daemon starting... Aug 31 18:42:22 bcik volumio[10081]: error: Cannot start Volumio Streaming Daemon Aug 31 18:42:22 bcik volumio[10081]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 18:42:22 bcik volumio[10081]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=debug msg="app state loaded" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:22 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. Aug 31 18:42:22 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. Aug 31 18:42:22 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. Aug 31 18:42:22 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. Aug 31 18:42:22 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. Aug 31 18:42:22 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. Aug 31 18:42:22 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. Aug 31 18:42:22 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. Aug 31 18:42:22 bcik sudo[10392]: pam_unix(sudo:session): session closed for user root Aug 31 18:42:22 bcik volumio[10081]: info: Remote SSH Stopped Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+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]" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+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]" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=info msg="zeroconf server listening on port 35913" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=debug msg="obtained new client token: AAGGRsCXVm4tsWlusPxXA26RBLPXENTWDJD96CgfN78egyOjgHhQlk75lb+9AUMgZeRs/UPZtT0T6PS3u2jOnYR8fjogEd4LBiU2Qya5Yy2HB6VrtmN090rM4dGFuN4ZGU84axBulrABEkCijLGocIKDEOGs1XxOPl7NMTpen7FUlNOHemK07FATjtxtmj0ciXh0y6TvrgTLfqfCFz/0SbZtzMEk/UpG1ZsloH7mbHUhBz4or9/h1+8=" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+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" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:22 bcik go-librespot[10394]: time="2026-08-31T18:42:22+02:00" level=debug msg="completed challenge" Aug 31 18:42:23 bcik volumio[10081]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 18:42:23 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:23 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:23 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:23 bcik go-librespot[10394]: time="2026-08-31T18:42:23+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:23 bcik go-librespot[10394]: time="2026-08-31T18:42:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:23 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:23 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:23 bcik volumio[10081]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 18:42:24 bcik volumio[10081]: info: Updating MyVolumio device info Aug 31 18:42:24 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:24 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:24 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:24 bcik volumio[10081]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 18:42:24 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:24 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 31 18:42:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:26 bcik go-librespot[10405]: go-librespot daemon starting... Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=debug msg="app state loaded" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+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]" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+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]" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=info msg="zeroconf server listening on port 37389" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=debug msg="obtained new client token: AAGd3GVcA2M3bHsMnD4QEi6acH/W3x2lg9HljIwNuebt6XR9/4fpQrgmFgNqwA5dwh/95VhKVsvOAbON/TmiMNPe4ycVSZhzfHGtS7aRXewUDkIr/i/t95t+6BhXL5UbRUZpEB0phUydODaBAfIhK8WU0j5p0q2483YV4fogBHiko1OrjWWQWxjDAiA/lN0f1IjXBqP8heYJEagmcdfQy1dEm8ZV0RGRtA8+rOATwLGHOqK4BVwDVdc=" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=debug msg="completed challenge" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:26 bcik go-librespot[10406]: time="2026-08-31T18:42:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:26 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:26 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:27 bcik volumio[10081]: info: MYVOLUMIO: Adding device Aug 31 18:42:27 bcik volumio[10081]: info: MYVOLUMIO: Evaluating Server Aug 31 18:42:27 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:27 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:27 bcik volumio[10081]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 18:42:27 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:27 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:27 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:28 bcik volumio[10081]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 18:42:28 bcik nmbd[1285]: [2026/08/31 18:42:28.572339, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Aug 31 18:42:28 bcik nmbd[1285]: register_name_response: Answer name <00> differs from question name <00>. Aug 31 18:42:28 bcik nmbd[1285]: [2026/08/31 18:42:28.572458, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Aug 31 18:42:28 bcik nmbd[1285]: register_name_response: Answer name <03> differs from question name <03>. Aug 31 18:42:28 bcik nmbd[1285]: [2026/08/31 18:42:28.572514, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Aug 31 18:42:28 bcik nmbd[1285]: register_name_response: Answer name <20> differs from question name <20>. Aug 31 18:42:28 bcik volumio[10081]: info: Updating MyVolumio device info Aug 31 18:42:28 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:28 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:28 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:29 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 31 18:42:29 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:29 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:29 bcik go-librespot[10433]: go-librespot daemon starting... Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42:29+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42:29+02:00" level=debug msg="app state loaded" Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:29 bcik volumio[10081]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42:29+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]" Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42:29+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]" Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42:29+02:00" level=info msg="zeroconf server listening on port 38347" Aug 31 18:42:29 bcik go-librespot[10434]: time="2026-08-31T18:42:29+02:00" level=debug msg="obtained new client token: AAFhtiUNH+3Es5x//Spn+IHvKYboHbxjx6e6oo91qXZDrCyRqRWwMGcjOhOfc3sycnpD+Jjz8F27qhvFWDKsvrdBb7rnhXyeWe5BHuNwoVDW0hBVkM5ylqAmBs/4htYaM1M3p2+g0stfhqqWswTmNGHQuz/nUdEuZYFY+cGHpCkSaxgNclCKAD42L7iemS9jRr//xltCFaKZOkWNfaShOUgvqDWSZF511NEdlKoyK7Hfm1cGavdg4WU=" Aug 31 18:42:30 bcik go-librespot[10434]: time="2026-08-31T18:42:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:30 bcik go-librespot[10434]: time="2026-08-31T18:42:30+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:30 bcik go-librespot[10434]: time="2026-08-31T18:42:30+02:00" level=debug msg="completed challenge" Aug 31 18:42:30 bcik go-librespot[10434]: time="2026-08-31T18:42:30+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:30 bcik go-librespot[10434]: time="2026-08-31T18:42:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:30 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:30 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:33 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:33 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 31 18:42:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:33 bcik go-librespot[10457]: go-librespot daemon starting... Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=debug msg="app state loaded" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42: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]" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42: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]" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42: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]" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=info msg="zeroconf server listening on port 45963" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=debug msg="obtained new client token: AAF2ZkV0mWFcjfzulYcgpxjxeAwa7gWvPz8Yht8h4x0FU5U/1TQyTkbjAmRuVWW/ZksvxrMNtXzaKpEZX7GR4uQQECwYleXbtczv+1MQpDqNb7tgu3opyS0h+Mw3tK/N1dM9GC9fCx+y7kOYRERI0wbEwoiIJb28RNbuR+ZI6kp8OxnB4ooVqVqVXeIAJ4CeWcNP1T/Z8tgXDZgA49dqZ9pGOmGTVuRvp9JlTbALRn11mZDTNs6SJOg=" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+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" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=debug msg="completed challenge" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:33 bcik go-librespot[10458]: time="2026-08-31T18:42:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:33 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:33 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:36 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 18:42:36 bcik volumio[10081]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 18:42:36 bcik volumio[10081]: info: CoreCommandRouter::volumioGetState Aug 31 18:42:36 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:42:36 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:36 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 31 18:42:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:37 bcik go-librespot[10468]: go-librespot daemon starting... Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=debug msg="app state loaded" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+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]" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+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]" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+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]" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=info msg="zeroconf server listening on port 34103" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=debug msg="obtained new client token: AAGQ4+c0WzrPq9zdNT0+hGvh4RlrQ3P8L//VRmr3tIJk9tnuYA9oupXVs8JLyTOUPZ3I55Eyn+uiYU2keTHTU3JYyi7UAcvpMuBsrjSZODBGJVjk7F6wYKgPNKDAe7tW6Em2JQTS9vyGwO3OhYx5KVmLHVPI3chLqjA41O2yT7HtzJXci4jAZcbjq9vsI7AI4rvBYSXBJjip0k2TVIUepM9a3XdfeKMgGUlZa+tl0BW/AEg9pbct" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=debug msg="completed challenge" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:37 bcik go-librespot[10469]: time="2026-08-31T18:42:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:39 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:39 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:40 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 31 18:42:40 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:40 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:40 bcik go-librespot[10478]: go-librespot daemon starting... Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=debug msg="app state loaded" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+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]" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+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]" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+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]" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=info msg="zeroconf server listening on port 45075" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=debug msg="obtained new client token: AAHmQY95mhTcbx2cxqpEAwLs69IpfT648W9xP4qUH4n1b3YCAbrFh06GcWlmhFBeMyNDtjjAkHBPDbp3R6/ZsWR6RSZRGIj9aPTKmRjG+ARtLQ/7AMZ8F+/MGE+FLOg+nE+N1m2g+IxSVX/ZaPMlvywHzKxhF3z9bVJdfZHzqrU/ar9UgXE1N8HKHDpvQt7MZEMd2L9ciOCEenZS8GYZYXSY9slZNuvPuWZEZQE+Qb6YyHCiioKIXlA=" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=debug msg="completed challenge" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:40 bcik go-librespot[10479]: time="2026-08-31T18:42:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:40 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:40 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:42:41 bcik volumio[10081]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 18:42:41 bcik volumio[10081]: info: Completed starting MyVolumio Plugin Aug 31 18:42:41 bcik volumio[10081]: [Metrics] CommandRouter: 30s 655.57ms Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::Close All Modals sent Aug 31 18:42:41 bcik volumio[10081]: info: CoreCommandRouter::Close All Modals sent Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 18:42:42 bcik volumio-remote-updater[962]: Test mode disabled Aug 31 18:42:42 bcik volumio-remote-updater[962]: Alpha mode disabled Aug 31 18:42:42 bcik volumio-remote-updater[962]: Alpha legacy test mode disabled Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 18:42:42 bcik volumio[10081]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 18:42:42 bcik volumio[10081]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 18:42:42 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:42 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:44 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 31 18:42:44 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:44 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:44 bcik go-librespot[10509]: go-librespot daemon starting... Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=debug msg="app state loaded" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+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]" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+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]" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+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]" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=info msg="zeroconf server listening on port 40923" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=debug msg="obtained new client token: AAHaxImRHLXo2L9AZ77m+CaVhaZPDk2BivYIFD2xmSOA9jIixL9WkOEnDLEYLopYJdZ29MzXJSwh5wZKzFRrhlxXaK4zU0UujKFSSntypqu5SWfJHKpW9ddjud40sCAx4kObPg5LuQG8yR65NMpvOM38+du0nnStGhSZiB95voj+gZNozJcjY76+5p9I8JYUbQUWdDQqDzwHyhjdzlTFF7bZROny8gkw7v5mDUgxRzhKYnnCWEuR" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+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" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=debug msg="completed challenge" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:44 bcik go-librespot[10510]: time="2026-08-31T18:42:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:44 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:44 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:45 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:45 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:47 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 31 18:42:47 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:47 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:47 bcik go-librespot[10520]: go-librespot daemon starting... Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=debug msg="app state loaded" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+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]" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+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]" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+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]" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=info msg="zeroconf server listening on port 45063" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=debug msg="obtained new client token: AAHKwl8edjYB1RmBXQZktkZoEkje8Ti7jNvLgvJoaWl7ctg7RkCW4ZT09qAMjU+Efo0EXXiYX4hOmAI4DABanBxI9oe+KtYAHzUsl/WdB+eo6RQ6AMfqR8JwWc1bY2ReqHMJwayYrGfX/rT8i4ZxiYgd3j5R4sNImOQ7HjQs+78aZGTFP0XMPIQD23oQGpg10xM1lCjY4eBqquf9MLxx1PnJDhANOZDipRpDENR2bEGx7Y9cU4tjVxk=" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+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" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=debug msg="completed challenge" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:47 bcik go-librespot[10521]: time="2026-08-31T18:42:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:47 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:47 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:48 bcik volumio[10081]: info: BOOT COMPLETED Aug 31 18:42:48 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:48 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:51 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 31 18:42:51 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:51 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:51 bcik go-librespot[10530]: go-librespot daemon starting... Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=debug msg="app state loaded" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+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]" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+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]" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+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]" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=info msg="zeroconf server listening on port 46123" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=debug msg="obtained new client token: AAE16EiJU4279XtpMvbNrRKe28Wfao8b7lYHxeQm32OWZe8SoNs2CYwvWQ8yTWfi0VhTLD1Pz71DgQ1hpqTO5A8dRFlfbzSK4QiRpEUvokZEbF1kMr6Yh2foEjCrBASiy9CN+V0dcU0E1vbEY2hpHWG8qgevXu+6UzixjSp7l59v6v1jZBdfHgDulImxScf94E63okKPgUppV1M1j+Rzo0kfF91Vp9WqDFnxF7zETEsb3EdjOb+0" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=debug msg="completed challenge" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:51 bcik go-librespot[10531]: time="2026-08-31T18:42:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:51 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:51 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:51 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:51 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:54 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:54 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:54 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 31 18:42:54 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:54 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:54 bcik go-librespot[10554]: go-librespot daemon starting... Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=debug msg="app state loaded" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+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]" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+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]" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+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]" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=info msg="zeroconf server listening on port 37491" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=debug msg="obtained new client token: AAE52sEt4k3zx3ReRiZ7c+3C33mHkz9Fr/w7b32U8UPxFI+sW0Bz8cLQAEbM5uiSpikHwW70GFkNY7bSk7puMCwcFCGiUelrLIR8MTV3lmJtNwCmoERsjhZYkOtwkY/5AtmhfBcVqHh4UPgFgsfC9YAxD0FJIKWhMIbIU/VWnB0ckPApGFlsNxIHKTbUgQgpYzl/CTp6/dBcpLz3xNBSXmeWPhClU2W0Suqt/7Yr+oLCGEBrgGWTfJk=" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=debug msg="completed challenge" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:54 bcik go-librespot[10555]: time="2026-08-31T18:42:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:54 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:54 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:42:57 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:42:57 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:42:58 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 31 18:42:58 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:58 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:42:58 bcik go-librespot[10567]: go-librespot daemon starting... Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=debug msg="app state loaded" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+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]" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+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]" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+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]" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=info msg="zeroconf server listening on port 44107" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=debug msg="obtained new client token: AAEWCmcL0YEBi88o4qYcRYPXjQfvGj9y/AXcoCTQb1uWiKhvAH0kmwZnq4W9eNP84t/elw/MmMfsKoxtptQ+/fum1GhYAdekO/0klvAu7wzXc6mVTWS/cWIC3BPoawM6ODTZqdwJur8xtArQMgYqOweTVhrhFJRxYGQW0uA3Q5wdLwSFghTPifW8NdyeKWhT8J0FfpKCHhVAo0JF+s4UzvOckmu6fJAIWxSaZi/H8gpjRwIJKR81" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+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" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=debug msg="completed keyexchange" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=debug msg="completed challenge" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:42:58 bcik go-librespot[10568]: time="2026-08-31T18:42:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:42:58 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:42:58 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:43:00 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:43:00 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:43:01 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 31 18:43:01 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:43:01 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:43:01 bcik go-librespot[10591]: go-librespot daemon starting... Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=debug msg="app state loaded" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+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]" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+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]" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=info msg="zeroconf server listening on port 42165" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=debug msg="obtained new client token: AAF7j0P8POqGJmWnwYT4/X+pt9fCNRljGYkZX2TChVatGO55+zvPhEpduz9ihnISav1p70Ji4KZH7Fu6zTaHooJNp3m9OwFNbdwCezE0Pb3GS+LtEeTZ/2XYeIecevcdO/mxDuMI8v9kCjgU4BEVB1QxSS8TyS2EXFudi1zo0zEXF25G0pvTS9xD4XhcL5RQw+0MDGrgYafN1K9/ROxjueHW2yAvCpzDeESJDmLQ53XE9cUZDpo71ZQ=" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=debug msg="completed keyexchange" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=debug msg="completed challenge" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:43:01 bcik go-librespot[10592]: time="2026-08-31T18:43:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:43:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:43:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:43:03 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:43:03 bcik volumio[10081]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 18:43:05 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 31 18:43:05 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:43:05 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 18:43:05 bcik go-librespot[10602]: go-librespot daemon starting... Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+02:00" level=debug msg="app state loaded" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+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]" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+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]" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+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]" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+02:00" level=info msg="zeroconf server listening on port 38015" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+02:00" level=debug msg="obtained new client token: AAG12xiRdZEIO3V9Xk2wvYPWeKEtv3I0VHJ/FVWah3uvq3BnQepVUBCi273W2aU/vHHOWnq6Y5lfZ3HRkKw1fnzerQKPFAnXo3tkOu3d3dm2ld6gj5uzrJugZhCto9AEXPpRcXzC+cz/XHPs1hNKWh6FKIgGorRuv0lEhRfGgUX0eVD1GJrYjsjeie5O90ZJV0v/OMenv3yTBLA+34ZgL9mhkeoRgy6jscQeYFivA7czSeIYdUz2" Aug 31 18:43:05 bcik go-librespot[10603]: time="2026-08-31T18:43:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 18:43:06 bcik volumio[10081]: info: Initializing connection to go-librespot Websocket Aug 31 18:43:06 bcik go-librespot[10603]: time="2026-08-31T18:43:06+02:00" level=debug msg="new websocket client" Aug 31 18:43:06 bcik volumio[10081]: info: Connection to go-librespot Websocket established Aug 31 18:43:09 bcik volumio[10081]: info: Getting Spotify volume Aug 31 18:43:09 bcik volumio[10081]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 31 18:43:09 bcik volumio[10081]: info: CoreCommandRouter::volumioGetState Aug 31 18:43:09 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:43:09 bcik volumio[10081]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Aug 31 18:43:09 bcik volumio[10081]: SPOTIFY: SPOTIFY VOLUME undefined Aug 31 18:43:09 bcik volumio[10081]: SPOTIFY: VOLUMIO VOLUME 53 Aug 31 18:43:09 bcik volumio[10081]: info: Aligning Spotify Volume to Volumio Volume Aug 31 18:43:09 bcik volumio[10081]: info: CoreCommandRouter::volumioGetState Aug 31 18:43:09 bcik volumio[10081]: info: CorePlayQueue::getTrack 0 Aug 31 18:43:09 bcik volumio[10081]: info: Setting Spotify Volume from Volumio: 53 Aug 31 18:43:10 bcik go-librespot[10603]: time="2026-08-31T18:43:10+02:00" level=debug msg="completed keyexchange" Aug 31 18:43:10 bcik go-librespot[10603]: time="2026-08-31T18:43:10+02:00" level=debug msg="completed challenge" Aug 31 18:43:10 bcik go-librespot[10603]: time="2026-08-31T18:43:10+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 18:43:10 bcik go-librespot[10603]: time="2026-08-31T18:43:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 18:43:10 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 18:43:10 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 18:43:10 bcik volumio[10081]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:43:10 bcik volumio[10081]: Error: socket hang up Aug 31 18:43:10 bcik volumio[10081]: at connResetException (node:internal/errors:720:14) Aug 31 18:43:10 bcik volumio[10081]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 31 18:43:10 bcik volumio[10081]: at Socket.emit (node:events:526:35) Aug 31 18:43:10 bcik volumio[10081]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 31 18:43:10 bcik volumio[10081]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 31 18:43:10 bcik volumio[10081]: code: 'ECONNRESET', Aug 31 18:43:10 bcik volumio[10081]: response: undefined Aug 31 18:43:10 bcik volumio[10081]: } Aug 31 18:43:10 bcik volumio[10081]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:43:10 bcik sudo[10626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 18:42' Aug 31 18:43:10 bcik sudo[10626]: 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"