Oct 16 17:23:00 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:00 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:01 bcik volumio[14927]: info: MYVOLUMIO: Adding device Oct 16 17:23:01 bcik volumio[14927]: info: MYVOLUMIO: Evaluating Server Oct 16 17:23:01 bcik volumio[14927]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:23:01 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:01 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:01 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:01 bcik volumio[14927]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:23:02 bcik volumio[14927]: info: Updating MyVolumio device info Oct 16 17:23:02 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:02 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:02 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:02 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Oct 16 17:23:02 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:02 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:02 bcik go-librespot[15290]: go-librespot daemon starting... Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="app state loaded" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:02 bcik volumio[14927]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=info msg="zeroconf server listening on port 37927" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="obtained new client token: AAHunVCsd3TaJuRBDllwPd04y1gwjsH8l2NqE84p/3vtQZOvOSRRXyKbiz9sJNnNygkpSXOuF3B44JWdRks844WTeo84bjJrtdWfgkc8TIhvVuhTXiTghVWffwzl8Lrs0LaT1v/FePhPwPLIJo0Ffuqr1Je79jwxF7IqfAgmNCzyCIrN51GfmodQVdqifQHYfgS4zlXQJ28d921gd3mE0QhutW8SRnMzMnp1EnrQCMbU806ty6GjILM=" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=debug msg="completed challenge" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:03 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:03 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:06 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:06 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:06 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Oct 16 17:23:06 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:06 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:06 bcik go-librespot[15314]: go-librespot daemon starting... Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="app state loaded" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23: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]" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23: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]" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23: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]" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="zeroconf server listening on port 39565" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="obtained new client token: AAENl2tX1lK6ANkvzP/JKqBt7/k3WNXjwp7NVtJGxCO/sdFYv+iEj2Z4pvJp4oIP9gHQXh/gfzEoa80tKhaFkB3luxraERgslDxNn6d9NW89E2iz8n4+M/ZJts6SBDmcJNHaCOC0OcV3cWkMVbx98Uwj1PWgODypFfapS6Y+JHKDxtmkA+krmYx/I4yL9eGt9EPWgrSlH6djjp6KVRjfMeqPSPTvcqCQNoHRuvrf3OHknqp98ty9PuM=" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="completed challenge" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:09 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 17:23:09 bcik volumio[14927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 16 17:23:09 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:09 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:09 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:09 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:10 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Oct 16 17:23:10 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:10 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:10 bcik go-librespot[15324]: go-librespot daemon starting... Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="app state loaded" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="zeroconf server listening on port 35415" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="obtained new client token: AAGvcr+cZ00wOVk68lFGZfdscsHysaqUSapoXnF80vzOIzc6XB/9Wx0J8sihklIFdSftc3uvRkFQAF+JJDzOwnAsDIob6GP1YChhdaL2sDexRJfIKIhL2EJTG8FnsKktzwmg2vV1SVqiNGLYsERmKet3FdOPOZjz89lM8Al2gYXwjHn2ACSSue3Kq8pMvCGxkI6FjgxfqnZIhNv6sxhQCXyLfAPxYmxMmdngWOuAx/oSxvUFasb2" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="completed challenge" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:10 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:10 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:12 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:12 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:13 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Oct 16 17:23:13 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:13 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:13 bcik go-librespot[15348]: go-librespot daemon starting... Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=debug msg="app state loaded" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=info msg="zeroconf server listening on port 43309" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=debug msg="obtained new client token: AAE7jJshkaV8lS/azwxJHBUDPNyu8xeooVq8WtIh39Uz5DEdrV7vBU+/W+j4J5uHPJBh3jmRa94HKnwyMGuGsDbz4TntGocjfnxdAb3cJ0U99V/GQjnxeCMkPyQGN77p/7XXHKLFCGqfMr3Tj8C2uDIQ3rm+KmNiZXTFeHnmg2I7CE6yP4D62LmRmOzxUP27juSP1mq3dqTz1AKKLm3rfDq6y9u6Dv2hXJ4krVSElwFh7NznTAEODOE=" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::volumioGetBrowseSources Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=debug msg="completed challenge" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:14 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:14 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:14 bcik volumio[14927]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 16 17:23:14 bcik volumio[14927]: info: Completed starting MyVolumio Plugin Oct 16 17:23:14 bcik volumio[14927]: [Metrics] CommandRouter: 31s 17.23ms Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::volumiosetStartupVolume Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::Close All Modals sent Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::Close All Modals sent Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 17:23:14 bcik volumio-remote-updater[9031]: Test mode disabled Oct 16 17:23:14 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 16 17:23:14 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 16 17:23:14 bcik volumio[14927]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 16 17:23:15 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:15 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:15 bcik volumio5-onboarding[15165]: time=2026-10-16T17:23:15.288+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15165]: time=2026-10-16T17:23:15.289+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15165]: time=2026-10-16T17:23:15.289+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:15 bcik volumio5-onboarding[15165]: failed to bootstrap state: failed to get available plugins: could not get available plugins: context deadline exceeded Oct 16 17:23:15 bcik systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:15 bcik systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 16 17:23:15 bcik systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 364. Oct 16 17:23:15 bcik systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 16 17:23:15 bcik systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.585+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 16 17:23:15 bcik volumio[14927]: 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: 4 Oct 16 17:23:15 bcik volumio[14927]: info: Received Get System Info Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:23:15 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:15 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.597+02:00 level=INFO msg="system info for 7d49fb3f7a1eba2a5cb01ee26de5f650" deviceName=Bącik deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 16 17:23:15 bcik volumio[14927]: 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: 4 Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.603+02:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 16 17:23:15 bcik volumio[14927]: info: Received Get System Info Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:23:15 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:15 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:23:15 bcik volumio-remote-updater[9031]: Test mode disabled Oct 16 17:23:15 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 16 17:23:15 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 16 17:23:15 bcik volumio[14927]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.952+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.953+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.953+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:16 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:16 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:17 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:17.033+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=9ixt1umkBgVYLY7gQzekBTAkTI72 tokenExpiry=2026-10-16T18:23:17.033+02:00 Oct 16 17:23:17 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Oct 16 17:23:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:17 bcik go-librespot[15378]: go-librespot daemon starting... Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="app state loaded" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="zeroconf server listening on port 38091" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="obtained new client token: AAGrFIYDOKMW84pu8ylNTB/3WGzrwmRMPuVe+370l5tosOQJvA9bx5L+UK/+skBc3XAnXPTlXxS82qFm1pbkrT/mOCNfrVc3FOh+Xaml38Ah96iIfAZZyeiAaVcOQGhQ79p6zxlW68tTNYaRNkGANBlGx4rHSxlzXWULh1bZSxnegsAB1sI2GYQhOX+HDwRAE2KfSx/bep0oZu6bZxxJJazru329ngDVXcq84DaIUsyTuEimAqdI8HA=" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="completed challenge" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:17 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:17 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:17 bcik volumio[14927]: info: Received Get System Info Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:23:17 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:17 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 17:23:17 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:17.753+02:00 level=INFO msg="enabling local network discovery" Oct 16 17:23:17 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:17.759+02:00 level=INFO msg="enabling BLE discovery" Oct 16 17:23:18 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:18 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:18 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:18.774+02:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 16 17:23:20 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Oct 16 17:23:20 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:20 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:20 bcik go-librespot[15390]: go-librespot daemon starting... Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=debug msg="app state loaded" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=info msg="zeroconf server listening on port 36227" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="obtained new client token: AAFlomq5LVfShvINsRwwAfXG/QdfFOlA5FMmy/8lOBp5gAKYahso3geoVTaXxD/tooC3uvd9acc3TLQaxpaPIacZeAD8Ay0C2pm02hWchwVL9R8YYj4tfSbSa2/oC1pwrUZGkrB1SvFtkIVIEIpZXi32NNFW2xJt5pqd57PksdNBemE4qjvJOEgqBUzIgTe/UDMVhVoZeZTD7oQO+bSF2db6N9g1DweyIPbzyOKG6Y/uf2Ayy201" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="completed challenge" Oct 16 17:23:21 bcik volumio[14927]: info: BOOT COMPLETED Oct 16 17:23:21 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="new websocket client" Oct 16 17:23:21 bcik volumio[14927]: info: Connection to go-librespot Websocket established Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:21 bcik volumio[14927]: info: Connection to go-librespot Websocket closed Oct 16 17:23:24 bcik volumio[14927]: info: Getting Spotify volume Oct 16 17:23:24 bcik volumio[14927]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:24 bcik volumio[14927]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:24 bcik volumio[14927]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 16 17:23:24 bcik volumio[14927]: errno: -111, Oct 16 17:23:24 bcik volumio[14927]: code: 'ECONNREFUSED', Oct 16 17:23:24 bcik volumio[14927]: syscall: 'connect', Oct 16 17:23:24 bcik volumio[14927]: address: '127.0.0.1', Oct 16 17:23:24 bcik volumio[14927]: port: 9879, Oct 16 17:23:24 bcik volumio[14927]: response: undefined Oct 16 17:23:24 bcik volumio[14927]: } Oct 16 17:23:24 bcik volumio[14927]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:24 bcik sudo[15429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 17:22' Oct 16 17:23:24 bcik sudo[15429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:24 bcik sudo[15429]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:24 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:24.481+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 16 17:23:24 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 16 17:23:24 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 16 17:23:24 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:24.482+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 16 17:23:24 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Oct 16 17:23:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:24 bcik go-librespot[15434]: go-librespot daemon starting... Oct 16 17:23:24 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 16 17:23:24 bcik systemd[1]: volumio.service: Consumed 7.030s CPU time. Oct 16 17:23:24 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="app state loaded" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:24 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="zeroconf server listening on port 34723" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="obtained new client token: AAHbFb0dW6v6YaacARXYGCMH1TyOTvFLcmBAn20nwAR2jvnbNEVU8TD12Pw/RKnIFMwc0afzhKRnLRTwlINc2/lMjbvZUCfs5OX+8yOC7BzAjCP3GRTZBFz8Wx+5cbGDQdLFRc9BTdetplV6kPn2uHMlgC7nclWQH8mcsZN97+X7ft1BagV7/z2mWZrsJr4q/hmbNoDLeH2Ndu5IT4DHBhJ8juJUFnzCb5cXxUDQMJzGqa7/Jf1XVRk=" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="completed challenge" Oct 16 17:23:24 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 27696. Oct 16 17:23:24 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:23:24 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 16 17:23:24 bcik systemd[1]: volumio.service: Consumed 7.030s CPU time. Oct 16 17:23:24 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 16 17:23:24 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:24 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:24 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: ----- Volumio3 ---- Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: ----- System startup ---- Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: MYVOLUMIO Environment detected Oct 16 17:23:25 bcik volumio[15453]: info: Plugin folders cleanup Oct 16 17:23:25 bcik volumio[15453]: info: Scanning into folder /volumio/app/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category audio_interface Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category miscellanea Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category music_service Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category plugins.json Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category system_controller Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category user_interface Oct 16 17:23:25 bcik volumio[15453]: info: Scanning into folder /data/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category music_service Oct 16 17:23:25 bcik volumio[15453]: info: Plugin folders cleanup completed Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: ----- Core plugins startup ---- Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugins from folder /volumio/app/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Adding plugin upnp to MyMusic Plugins Oct 16 17:23:25 bcik volumio[15453]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 16 17:23:25 bcik volumio[15453]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugins from folder /data/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "system"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "appearance"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "network"... Oct 16 17:23:25 bcik volumio[15453]: info: Refreshing Cached IP Addresses Oct 16 17:23:25 bcik sudo[15481]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:23:25 bcik sudo[15481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:25 bcik sudo[15483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:23:25 bcik sudo[15483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:25 bcik sudo[15481]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:25 bcik sudo[15483]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "services"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "volumio5onboarding"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "alsa_controller"... Oct 16 17:23:25 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "wizard"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "networkfs"... Oct 16 17:23:25 bcik volumio[15453]: info: Starting Udev Watcher for removable devices Oct 16 17:23:25 bcik volumio[15453]: info: Ignoring mount for partition: boot Oct 16 17:23:25 bcik volumio[15453]: info: Ignoring mount for partition: volumio Oct 16 17:23:25 bcik volumio[15453]: info: Ignoring mount for partition: volumio_data Oct 16 17:23:25 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "volumio_command_line_client"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "upnp"... Oct 16 17:23:25 bcik volumio[15453]: info: [1792164205615] Starting Upmpd Daemon Oct 16 17:23:25 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "my_music"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "mpd"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "upnp_browser"... Oct 16 17:23:25 bcik volumio[15453]: info: Starting UPNP Browser Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "alarm-clock"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "airplay_emulation"... Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "last_100"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "webradio"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "i2s_dacs"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "volumiodiscovery"... Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik node[15453]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik node[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik node[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik node[15453]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik node[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik node[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik volumio[15453]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 16 17:23:26 bcik volumio[15453]: info: Discovery: Started advertising with name: Bącik Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "spop"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "outputs"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "albumart"... Oct 16 17:23:26 bcik volumio[15453]: info: Plugin example_plugin is not enabled Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "inputs"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "updater_comm"... Oct 16 17:23:26 bcik volumio[15453]: info: Plugin mpdemulation is not enabled Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "rest_api"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "websocket"... Oct 16 17:23:26 bcik volumio[15453]: info: Starting Socket.io Server version 1.7.4 Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "radio_browser"... Oct 16 17:23:26 bcik volumio[15513]: Forking 3 albumart workers Oct 16 17:23:26 bcik volumio[15453]: info: Loading i18n strings for locale pl Oct 16 17:23:26 bcik volumio[15453]: Updating browse sources language Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::initPlayerControls Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: Express server listening on port 3000 Oct 16 17:23:26 bcik volumio[15453]: [Metrics] WebUI: 1s 286.53ms Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::resetVolumioState Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::getcurrentVolume Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:23:26 bcik volumio[15453]: info: Volumio Network Manager: Network status updated: 1 Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:26 bcik volumio[15453]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::updateTrackBlock Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrackBlock Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Reloading queue from file Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::setRepeat false single undefined Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::setRandom false Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: info: Setting Device type: Raspberry PI Oct 16 17:23:26 bcik volumio[15453]: info: Completed loading Core Plugins Oct 16 17:23:26 bcik volumio[15453]: info: Preparing to generate the ALSA configuration file Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:26 bcik volumio[15453]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 16 17:23:26 bcik volumio[15453]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 16 17:23:26 bcik volumio[15453]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 16 17:23:26 bcik volumio[15453]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:26 bcik volumio[15453]: info: Asound.conf file unchanged, so no further update is needed Oct 16 17:23:26 bcik volumio[15453]: info: Output device has changed, restarting MPD Oct 16 17:23:26 bcik volumio[15453]: info: Output device has changed, restarting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik sudo[15567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:23:26 bcik sudo[15567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:23:26 bcik sudo[15571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik volumio[15453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:26 bcik volumio[15453]: info: ___________ START PLUGINS ___________ Oct 16 17:23:26 bcik sudo[15567]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik volumio[15453]: info: ControllerMpd::onStart: Initializing MPD Oct 16 17:23:26 bcik volumio[15453]: info: Creating MPD Configuration file Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206533] CoreMusicLibrary::Adding element Serwery Mediów Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 16 17:23:26 bcik sudo[15580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:23:26 bcik sudo[15580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik volumio[15453]: info: UPNP Browser: Client initialized successfully Oct 16 17:23:26 bcik sudo[15580]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik sudo[15581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:23:26 bcik sudo[15581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 16 17:23:26 bcik sudo[15578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:23:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:23:26 bcik sudo[15578]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:23:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:23:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206609] CoreMusicLibrary::Adding element Last_100 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206610] CoreMusicLibrary::Adding element Webradio Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:26 bcik volumio[15453]: info: Initializing BBC Radios Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Creating Spotify config file Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik sudo[15596]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 17:23:26 bcik sudo[15596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 17:23:26 bcik sudo[15596]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik volumio[15525]: Starting albumart workers Oct 16 17:23:26 bcik volumio[15523]: Starting albumart workers Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206722] CoreMusicLibrary::Adding element Radio Browser Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: Cannot find translation for source Radio Browser Oct 16 17:23:26 bcik volumio[15453]: info: Volumio Calling Home Oct 16 17:23:26 bcik volumio[15524]: Starting albumart workers Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:26 bcik volumio[15453]: info: MPD Permissions set Oct 16 17:23:26 bcik volumio[15453]: info: MPD Permissions set Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 16 17:23:26 bcik volumio[15453]: info: Spotify config file written Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:26 bcik sudo[15615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 16 17:23:26 bcik sudo[15615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:26 bcik go-librespot[15624]: go-librespot daemon starting... Oct 16 17:23:26 bcik sudo[15615]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="app state loaded" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: No need to fix Spotify hosts Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:26 bcik volumio[15453]: info: Volumio called home Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik sudo[15645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:26 bcik sudo[15645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:26 bcik sudo[15644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:26 bcik sudo[15647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:26 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:26 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 17:23:26 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:26 bcik systemd[1]: shairport-sync.service: Consumed 1.544s CPU time. Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=info msg="zeroconf server listening on port 36349" Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 16 17:23:27 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:27 bcik sudo[15644]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik sudo[15647]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik sudo[15645]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:27 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:27 bcik volumio[15453]: info: Shairport-Sync Started Oct 16 17:23:27 bcik volumio[15453]: Error adding Membership: Error: addMembership EINVAL Oct 16 17:23:27 bcik volumio[15453]: info: Shairport-Sync Started Oct 16 17:23:27 bcik volumio[15453]: info: Shairport-Sync Started Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="obtained new client token: AAFIhlCT8+Kh5PzApGNIXNL0+sOVm5n4MbJ2mpoMoliikBeDngqfjThtnEE+SPzp6zjJfQPyI+WEo4sOzycjrcnNTtGs6YcqyYnYox6l6uCHvdxczhah0jdenUBx1yCpOTgaD83WiMx9Dbq6vgUFWtszGTviUHa4aG06U/ZGVMUDjsO4s257psX+H+oUmZb3RVGsHOgbTx0TScn06NFgxcBt2P2eG49ChNFDx8grjU5z+22w56qr" Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:23:27 bcik volumio[15453]: info: Discovery: Found device Bącik Oct 16 17:23:27 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:27 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:23:27 bcik volumio[15453]: info: Discovery: Found device Bącik Oct 16 17:23:27 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:27 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="completed challenge" Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:27 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik mpd[15611]: 2026-10-16T17:23:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik sudo[15581]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik sudo[15571]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: info: Completed starting Core Plugins Oct 16 17:23:27 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:27 bcik volumio[15453]: info: ----- MyVolumio plugins startup ---- Oct 16 17:23:27 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:27 bcik volumio[15453]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 16 17:23:27 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 17:23:27 bcik volumio[15453]: error: MPD error: The expression evaluated to a falsy value: Oct 16 17:23:27 bcik volumio[15453]: assert.ok(self.idling) Oct 16 17:23:27 bcik volumio[15453]: error: The expression evaluated to a falsy value: Oct 16 17:23:27 bcik volumio[15453]: assert.ok(self.idling) Oct 16 17:23:27 bcik volumio[15453]: info: MPD running with PID15611 Oct 16 17:23:27 bcik volumio[15453]: ,establishing connection Oct 16 17:23:27 bcik volumio[15453]: error: updateQueue error: null Oct 16 17:23:27 bcik volumio[15453]: error: updateQueue error: null Oct 16 17:23:29 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:29] [connect] Successful connection Oct 16 17:23:29 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1792164209 101 Oct 16 17:23:29 bcik volumio[15453]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Oct 16 17:23:29 bcik volumio[15453]: info: go-librespot daemon successfully initialized Oct 16 17:23:30 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Oct 16 17:23:30 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:30 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:30 bcik go-librespot[15686]: go-librespot daemon starting... Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="app state loaded" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="zeroconf server listening on port 46069" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="obtained new client token: AAE5mJkrpnMb1yoJ5CCN8SJCLkboNZBGHP+G1M9sOzBqcJQ5UiD6rzlsmPg0PQeF93xg7SIUJIwBQb3e7tU2eO7xAC9v7l7F5wUdHD/0w2BXZHI0t7cDutzyaUepW7FmvXp/+G9iPgT1ccfVucQh+0uRjoICejChQlpEcPaBES17QtK4LK3NakjpGF8HTJ+qa4fODO7KYYPZ7LiWkBt++w4ahPr9xjxNlO1ql+jGO4SsxJYJPpxbirE=" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="completed challenge" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:32 bcik volumio[15453]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 16 17:23:32 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:32 bcik volumio[15453]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Oct 16 17:23:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:33 bcik go-librespot[15696]: go-librespot daemon starting... Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="app state loaded" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=info msg="zeroconf server listening on port 42039" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="obtained new client token: AAFeqhk8O5uP11nFX9PiDWb+NED8/N+3Wx3Hfyc3BNJZ+IeM8wXAm+/83vBMxPpeyx+tSbWPdQoCQCcnvSpLle+7Yscpnphs3OfUOX5EtUP1iR1hJClflzQaq3y6vUJksJ/7LiJxjgeFkVEY/1caETnr/vpz8IWeNziOUFRaFOfnS0CJvuCRZANyuQv4AvRliijTD8NBa9R9socNsKSp6oLRbm77bZZpEf5kQ4/E7wqXLENU1VUIpw8=" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=debug msg="completed challenge" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:34 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:34 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin bluetooth to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin multiroom to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin metavolumio to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin cd_controller to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 16 17:23:35 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:35 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:35 bcik volumio[15453]: info: Starting MyVolumio Remote Streaming Endpoints Oct 16 17:23:35 bcik volumio[15453]: info: MyVolumio login type: Token Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 16 17:23:35 bcik volumio[15453]: info: Streaming services startup Oct 16 17:23:35 bcik volumio[15453]: info: Starting Streaming Daemon Oct 16 17:23:35 bcik sudo[15721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:23:35 bcik sudo[15721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 16 17:23:35 bcik sudo[15721]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik sudo[15728]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:23:35 bcik sudo[15728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik volumio[15453]: error: Cannot start Volumio Streaming Daemon Oct 16 17:23:35 bcik volumio[15453]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:23:35 bcik volumio[15453]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:23:35 bcik sudo[15730]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:23:35 bcik sudo[15730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik sudo[15730]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik sudo[15728]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik sudo[15734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 17:23:35 bcik sudo[15734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik sudo[15734]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik volumio[15453]: info: Upmpdcli Daemon Started Oct 16 17:23:35 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:35 bcik volumio[15453]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:36 bcik volumio[15453]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 16 17:23:36 bcik volumio[15453]: info: MyVolumio token set successfully Oct 16 17:23:36 bcik volumio[15453]: info: MYVOLUMIO: Adding device Oct 16 17:23:36 bcik volumio[15453]: info: MYVOLUMIO: Evaluating Server Oct 16 17:23:37 bcik volumio[15453]: info: MyVolumio status changed Oct 16 17:23:37 bcik volumio[15453]: info: Streaming services startup Oct 16 17:23:37 bcik volumio[15453]: info: Starting Streaming Daemon Oct 16 17:23:37 bcik volumio[15453]: info: Removing browser output: myVolumio user plan is not superstar Oct 16 17:23:37 bcik volumio[15453]: info: Removing audio output: Oct 16 17:23:37 bcik volumio[15453]: info: Stoppping Tunnel 1 Oct 16 17:23:37 bcik sudo[15757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:23:37 bcik sudo[15757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:37 bcik sudo[15759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 16 17:23:37 bcik sudo[15759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik sudo[15757]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:37 bcik volumio[15453]: error: Cannot start Volumio Streaming Daemon Oct 16 17:23:37 bcik sudo[15759]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:37 bcik volumio[15453]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:23:37 bcik volumio[15453]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:23:37 bcik volumio[15453]: info: Remote SSH Stopped Oct 16 17:23:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Oct 16 17:23:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:37 bcik go-librespot[15763]: go-librespot daemon starting... Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="app state loaded" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:37 bcik volumio[15453]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:23:37 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:37 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:37 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="zeroconf server listening on port 33079" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="obtained new client token: AAEtc9/nTGOmt/Ybs45pVACqxvQSdwxerUA9RtopYz2/NJ7p1h7yq+2X71aViqPhrSVwuCvEseE9VNW1YAj7DdSCP+Z4rXD2mPIh4KnJIfb9CdoLram7CYZLuiTm02cPVPP/FMDjbfVe+nfHxoNic5bcGWVJJZvTnuUJhYNf1Jm96+p8IjpUeqeOmudydHH9vAGB3Q+BYUBEdam/3b77L+e2Ex/Ihr9+UQ2vTc6ZCGcCyN6XzYbhX2U=" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="completed challenge" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:37 bcik volumio[15453]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:38 bcik volumio[15453]: info: Updating MyVolumio device info Oct 16 17:23:38 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:38 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:38 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:38 bcik volumio[15453]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:23:38 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:38 bcik volumio[15453]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:40 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Oct 16 17:23:40 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:40 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:40 bcik go-librespot[15774]: go-librespot daemon starting... Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=debug msg="app state loaded" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=info msg="zeroconf server listening on port 43053" Oct 16 17:23:41 bcik volumio[15453]: info: MYVOLUMIO: Adding device Oct 16 17:23:41 bcik volumio[15453]: info: MYVOLUMIO: Evaluating Server Oct 16 17:23:41 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:41 bcik go-librespot[15775]: time="2026-10-16T17:23:41+02:00" level=debug msg="new websocket client" Oct 16 17:23:41 bcik volumio[15453]: info: Connection to go-librespot Websocket established Oct 16 17:23:42 bcik volumio[15453]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:23:42 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:42 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:42 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:42 bcik volumio[15453]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:23:43 bcik volumio[15453]: info: Updating MyVolumio device info Oct 16 17:23:43 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:43 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:43 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:43 bcik volumio[15453]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:23:44 bcik volumio[15453]: info: Getting Spotify volume Oct 16 17:23:44 bcik volumio[15453]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 16 17:23:44 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:44 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:44 bcik volumio[15453]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Oct 16 17:23:44 bcik volumio[15453]: SPOTIFY: SPOTIFY VOLUME undefined Oct 16 17:23:44 bcik volumio[15453]: SPOTIFY: VOLUMIO VOLUME 41 Oct 16 17:23:44 bcik volumio[15453]: info: Aligning Spotify Volume to Volumio Volume Oct 16 17:23:44 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:44 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:44 bcik volumio[15453]: info: Setting Spotify Volume from Volumio: 41 Oct 16 17:23:46 bcik go-librespot[15775]: time="2026-10-16T17:23:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: invalid status code from clienttoken: 503" Oct 16 17:23:46 bcik volumio[15453]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:46 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:46 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:46 bcik volumio[15453]: Error: socket hang up Oct 16 17:23:46 bcik volumio[15453]: at connResetException (node:internal/errors:720:14) Oct 16 17:23:46 bcik volumio[15453]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 16 17:23:46 bcik volumio[15453]: at Socket.emit (node:events:526:35) Oct 16 17:23:46 bcik volumio[15453]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 16 17:23:46 bcik volumio[15453]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 16 17:23:46 bcik volumio[15453]: code: 'ECONNRESET', Oct 16 17:23:46 bcik volumio[15453]: response: undefined Oct 16 17:23:46 bcik volumio[15453]: } Oct 16 17:23:46 bcik volumio[15453]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:46 bcik sudo[15830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 17:22' Oct 16 17:23:46 bcik sudo[15830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:46 bcik sudo[15830]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:46 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 16 17:23:46 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 16 17:23:46 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:46.412+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 16 17:23:46 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:46.414+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 16 17:23:46 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:46 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 16 17:23:46 bcik systemd[1]: volumio.service: Consumed 6.586s CPU time. Oct 16 17:23:46 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:23:46 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:23:46 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 27697. Oct 16 17:23:46 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:23:46 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 16 17:23:46 bcik systemd[1]: volumio.service: Consumed 6.586s CPU time. Oct 16 17:23:46 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 16 17:23:46 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:23:46 bcik volumio[15845]: info: ------------------------------------------- Oct 16 17:23:46 bcik volumio[15845]: info: ----- Volumio3 ---- Oct 16 17:23:46 bcik volumio[15845]: info: ------------------------------------------- Oct 16 17:23:46 bcik volumio[15845]: info: ----- System startup ---- Oct 16 17:23:46 bcik volumio[15845]: info: ------------------------------------------- Oct 16 17:23:47 bcik volumio[15845]: info: MYVOLUMIO Environment detected Oct 16 17:23:47 bcik volumio[15845]: info: Plugin folders cleanup Oct 16 17:23:47 bcik volumio[15845]: info: Scanning into folder /volumio/app/plugins/ Oct 16 17:23:47 bcik volumio[15845]: info: Scanning category audio_interface Oct 16 17:23:47 bcik volumio[15845]: info: Scanning category miscellanea Oct 16 17:23:47 bcik volumio[15845]: info: Scanning category music_service Oct 16 17:23:47 bcik volumio[15845]: info: Scanning category plugins.json Oct 16 17:23:47 bcik volumio[15845]: info: Scanning category system_controller Oct 16 17:23:47 bcik volumio[15845]: info: Scanning category user_interface Oct 16 17:23:47 bcik volumio[15845]: info: Scanning into folder /data/plugins/ Oct 16 17:23:47 bcik volumio[15845]: info: Scanning category music_service Oct 16 17:23:47 bcik volumio[15845]: info: Plugin folders cleanup completed Oct 16 17:23:47 bcik volumio[15845]: info: ------------------------------------------- Oct 16 17:23:47 bcik volumio[15845]: info: ----- Core plugins startup ---- Oct 16 17:23:47 bcik volumio[15845]: info: ------------------------------------------- Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugins from folder /volumio/app/plugins/ Oct 16 17:23:47 bcik volumio[15845]: info: Adding plugin upnp to MyMusic Plugins Oct 16 17:23:47 bcik volumio[15845]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 16 17:23:47 bcik volumio[15845]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugins from folder /data/plugins/ Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "system"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "appearance"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "network"... Oct 16 17:23:47 bcik volumio[15845]: info: Refreshing Cached IP Addresses Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "services"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "volumio5onboarding"... Oct 16 17:23:47 bcik sudo[15875]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:23:47 bcik sudo[15875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:47 bcik sudo[15875]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:47 bcik sudo[15873]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:23:47 bcik sudo[15873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:47 bcik sudo[15873]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "alsa_controller"... Oct 16 17:23:47 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "wizard"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "networkfs"... Oct 16 17:23:47 bcik volumio[15845]: info: Starting Udev Watcher for removable devices Oct 16 17:23:47 bcik volumio[15845]: info: Ignoring mount for partition: boot Oct 16 17:23:47 bcik volumio[15845]: info: Ignoring mount for partition: volumio Oct 16 17:23:47 bcik volumio[15845]: info: Ignoring mount for partition: volumio_data Oct 16 17:23:47 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "volumio_command_line_client"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "upnp"... Oct 16 17:23:47 bcik volumio[15845]: info: [1792164227353] Starting Upmpd Daemon Oct 16 17:23:47 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "my_music"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "mpd"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "upnp_browser"... Oct 16 17:23:47 bcik volumio[15845]: info: Starting UPNP Browser Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "alarm-clock"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "airplay_emulation"... Oct 16 17:23:47 bcik volumio[15845]: info: Starting Shairport Sync Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "last_100"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "webradio"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "i2s_dacs"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "volumiodiscovery"... Oct 16 17:23:47 bcik volumio[15845]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:47 bcik volumio[15845]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:47 bcik volumio[15845]: *** WARNING *** For more information see Oct 16 17:23:47 bcik volumio[15845]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:47 bcik volumio[15845]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:47 bcik volumio[15845]: *** WARNING *** For more information see Oct 16 17:23:47 bcik node[15845]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:47 bcik node[15845]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:47 bcik node[15845]: *** WARNING *** For more information see Oct 16 17:23:47 bcik node[15845]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:47 bcik node[15845]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:47 bcik node[15845]: *** WARNING *** For more information see Oct 16 17:23:47 bcik volumio[15845]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 16 17:23:47 bcik volumio[15845]: info: Discovery: Started advertising with name: Bącik Oct 16 17:23:47 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "spop"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "outputs"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "albumart"... Oct 16 17:23:47 bcik volumio[15845]: info: Plugin example_plugin is not enabled Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "inputs"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "updater_comm"... Oct 16 17:23:47 bcik volumio[15845]: info: Plugin mpdemulation is not enabled Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "rest_api"... Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "websocket"... Oct 16 17:23:47 bcik volumio[15845]: info: Starting Socket.io Server version 1.7.4 Oct 16 17:23:47 bcik volumio[15845]: info: Loading plugin "radio_browser"... Oct 16 17:23:48 bcik volumio[15905]: Forking 3 albumart workers Oct 16 17:23:48 bcik volumio[15845]: info: Loading i18n strings for locale pl Oct 16 17:23:48 bcik volumio[15845]: Updating browse sources language Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::initPlayerControls Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: Express server listening on port 3000 Oct 16 17:23:48 bcik volumio[15845]: [Metrics] WebUI: 1s 262.28ms Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::resetVolumioState Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::getcurrentVolume Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:23:48 bcik volumio[15845]: info: Volumio Network Manager: Network status updated: 1 Oct 16 17:23:48 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: Reloading queue from file Oct 16 17:23:48 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::setRepeat false single undefined Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::pushState Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::setRandom false Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::pushState Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:48 bcik volumio[15845]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::pushState Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::updateTrackBlock Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrackBlock Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:23:48 bcik volumio[15845]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 16 17:23:48 bcik volumio[15845]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 16 17:23:48 bcik volumio[15845]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 16 17:23:48 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:48 bcik volumio[15845]: info: Setting Device type: Raspberry PI Oct 16 17:23:48 bcik volumio[15845]: info: Completed loading Core Plugins Oct 16 17:23:48 bcik volumio[15845]: info: Preparing to generate the ALSA configuration file Oct 16 17:23:48 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:48 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:48 bcik volumio[15845]: info: Asound.conf file unchanged, so no further update is needed Oct 16 17:23:48 bcik volumio[15845]: info: Output device has changed, restarting MPD Oct 16 17:23:48 bcik volumio[15845]: info: Output device has changed, restarting Shairport Sync Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:48 bcik sudo[15960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:23:48 bcik sudo[15963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:23:48 bcik sudo[15963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik sudo[15960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik sudo[15960]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik volumio[15845]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:48 bcik volumio[15845]: info: ___________ START PLUGINS ___________ Oct 16 17:23:48 bcik volumio[15845]: info: ControllerMpd::onStart: Initializing MPD Oct 16 17:23:48 bcik volumio[15845]: info: Creating MPD Configuration file Oct 16 17:23:48 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 16 17:23:48 bcik sudo[15969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 16 17:23:48 bcik sudo[15969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik sudo[15972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:23:48 bcik sudo[15972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:48 bcik volumio[15845]: info: [1792164228291] CoreMusicLibrary::Adding element Serwery Mediów Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:48 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:23:48 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:23:48 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:23:48 bcik volumio[15845]: info: UPNP Browser: Client initialized successfully Oct 16 17:23:48 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:23:48 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:23:48 bcik sudo[15972]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik sudo[15975]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:23:48 bcik sudo[15975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:48 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:23:48 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:23:48 bcik volumio[15845]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:48 bcik volumio[15845]: info: [1792164228337] CoreMusicLibrary::Adding element Last_100 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:48 bcik volumio[15845]: info: [1792164228338] CoreMusicLibrary::Adding element Webradio Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:48 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:23:48 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:23:48 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:23:48 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:23:48 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:23:48 bcik sudo[15969]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:23:48 bcik volumio[15845]: info: Initializing BBC Radios Oct 16 17:23:48 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:48 bcik volumio[15916]: Starting albumart workers Oct 16 17:23:48 bcik volumio[15845]: info: Creating Spotify config file Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik sudo[15989]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 17:23:48 bcik sudo[15989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 17:23:48 bcik sudo[15989]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik volumio[15915]: Starting albumart workers Oct 16 17:23:48 bcik volumio[15917]: Starting albumart workers Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:48 bcik volumio[15845]: info: [1792164228588] CoreMusicLibrary::Adding element Radio Browser Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:48 bcik volumio[15845]: Cannot find translation for source Radio Browser Oct 16 17:23:48 bcik volumio[15845]: info: Volumio Calling Home Oct 16 17:23:48 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 16 17:23:48 bcik volumio[15845]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:23:48 bcik volumio[15845]: info: CoreStateMachine::pushState Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:48 bcik volumio[15845]: info: MPD Permissions set Oct 16 17:23:48 bcik volumio[15845]: info: MPD Permissions set Oct 16 17:23:48 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 16 17:23:48 bcik volumio[15845]: info: Spotify config file written Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik sudo[16028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 16 17:23:48 bcik sudo[16028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:48 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:48 bcik volumio[15845]: info: No need to fix Spotify hosts Oct 16 17:23:48 bcik volumio[15845]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:23:48 bcik volumio[15845]: info: Discovery: Found device Bącik Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:48 bcik volumio[15845]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:23:48 bcik volumio[15845]: info: Discovery: Found device Bącik Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:48 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:48 bcik volumio[15845]: info: Volumio called home Oct 16 17:23:48 bcik go-librespot[16040]: go-librespot daemon starting... Oct 16 17:23:48 bcik sudo[16028]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="app state loaded" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:48 bcik volumio[15845]: info: Starting Shairport Sync Oct 16 17:23:48 bcik volumio[15845]: info: Starting Shairport Sync Oct 16 17:23:48 bcik volumio[15845]: info: Starting Shairport Sync Oct 16 17:23:48 bcik sudo[16048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:48 bcik sudo[16048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik sudo[16050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:48 bcik sudo[16050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 17:23:48 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 17:23:48 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:48 bcik systemd[1]: shairport-sync.service: Consumed 1.527s CPU time. Oct 16 17:23:48 bcik sudo[16053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:48 bcik sudo[16053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:48 bcik volumio[15845]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:48 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:48 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:48 bcik sudo[16048]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik sudo[16050]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik volumio[15845]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 16 17:23:48 bcik volumio[15845]: info: Shairport-Sync Started Oct 16 17:23:48 bcik volumio[15845]: Error adding Membership: Error: addMembership EINVAL Oct 16 17:23:48 bcik volumio[15845]: info: Shairport-Sync Started Oct 16 17:23:48 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 17:23:48 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 17:23:48 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:48 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:48 bcik sudo[16053]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik volumio[15845]: info: Shairport-Sync Started Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=info msg="zeroconf server listening on port 36963" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="obtained new client token: AAFccpn9VplBPmQVonyfqEUbHo+K+/XQCu6XQDYS5+/PGOQWWjLn52f6lhDEi+CZkonrqZ9VxRMKwMmZEJkiNMEvrfiF2m2a+nmLwf8lhsTjqyojtn+gJksfvrYPTWl/Zq6SCOcXzBngy8s0BxL54+0Gn3VN7Dqj7tyJfVXjXql9ASA6htK4SA0pbyoghyUBW9KvKX6esqEPmFjHsXcwnD52oMTAOQEWgWChtyiZAEvP+nuLMc2ksW8=" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:48 bcik mpd[16003]: 2026-10-16T17:23:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 17:23:48 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 16 17:23:48 bcik sudo[15975]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik sudo[15963]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:48 bcik volumio[15845]: info: Completed starting Core Plugins Oct 16 17:23:48 bcik volumio[15845]: info: ------------------------------------------- Oct 16 17:23:48 bcik volumio[15845]: info: ----- MyVolumio plugins startup ---- Oct 16 17:23:48 bcik volumio[15845]: info: ------------------------------------------- Oct 16 17:23:48 bcik volumio[15845]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:48 bcik go-librespot[16041]: time="2026-10-16T17:23:48+02:00" level=debug msg="completed challenge" Oct 16 17:23:48 bcik volumio[15845]: error: MPD error: The expression evaluated to a falsy value: Oct 16 17:23:48 bcik volumio[15845]: assert.ok(self.idling) Oct 16 17:23:48 bcik volumio[15845]: error: The expression evaluated to a falsy value: Oct 16 17:23:48 bcik volumio[15845]: assert.ok(self.idling) Oct 16 17:23:48 bcik volumio[15845]: info: MPD running with PID16003 Oct 16 17:23:48 bcik volumio[15845]: ,establishing connection Oct 16 17:23:48 bcik volumio[15845]: error: updateQueue error: null Oct 16 17:23:48 bcik volumio[15845]: error: updateQueue error: null Oct 16 17:23:49 bcik go-librespot[16041]: time="2026-10-16T17:23:49+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:49 bcik go-librespot[16041]: time="2026-10-16T17:23:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:49 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:49 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:51 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:51] [connect] Successful connection Oct 16 17:23:51 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1792164231 101 Oct 16 17:23:51 bcik volumio[15845]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Oct 16 17:23:51 bcik volumio[15845]: info: go-librespot daemon successfully initialized Oct 16 17:23:52 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 105. Oct 16 17:23:52 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:52 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:52 bcik go-librespot[16079]: go-librespot daemon starting... Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="app state loaded" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=info msg="zeroconf server listening on port 43897" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="obtained new client token: AAHoT/J1gm+aCWoqI2t4Yh1Bxa6DdlfxGBv+oRVDmevs+dG2mItPiIyoLnLCCtqv8w8dR7eh3Ug+7DTqDXhGnUupQmOHsmzQ43KGu45sndFDfIa+AqqnvjJAmrJJqewo38fKtHmXOhlkiVnl3CcuJNK/rM3Uo3JIsuUssufxMDq5TJVQ/EivKrgpOX3sE4fbg5XNp4kLuoDo4gncM8H4Xz4nVFkRiCwba7uesMxjF2h0CGlcPXxd6Qo=" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=debug msg="completed challenge" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:52 bcik go-librespot[16080]: time="2026-10-16T17:23:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:52 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:52 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:53 bcik volumio[15845]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 16 17:23:54 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:54 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:56 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 106. Oct 16 17:23:56 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:56 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:56 bcik go-librespot[16089]: go-librespot daemon starting... Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="app state loaded" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=info msg="zeroconf server listening on port 44441" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="obtained new client token: AAHLq7t8mwCR7yjzOcqn3zsOii50ppZOIWPP4LGrCP4mbi5Kwpjg6EXF3mmBTdH8lRIcRzEkFCr6LOCYFmAx3krj+PLJsV0F7M6dySEwY7eANNuBVdcuyFbK8XD+BjlQNCmsX+WR+18MIrHp1+P02NMiGR0H1A9iI0t6iwBYbJVGU+G4PTPuVcFc9ZFJtKKre364NXK5TUsnzNWGLhsUazRxV2QD95t2LBrO7Ld5KVPhlcJPZM05G9I=" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=debug msg="completed challenge" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:56 bcik go-librespot[16090]: time="2026-10-16T17:23:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:56 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:56 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 16 17:23:57 bcik volumio[15845]: info: Adding plugin bluetooth to MyMusic Plugins Oct 16 17:23:57 bcik volumio[15845]: info: Adding plugin multiroom to MyMusic Plugins Oct 16 17:23:57 bcik volumio[15845]: info: Adding plugin metavolumio to MyMusic Plugins Oct 16 17:23:57 bcik volumio[15845]: info: Adding plugin cd_controller to MyMusic Plugins Oct 16 17:23:57 bcik volumio[15845]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 16 17:23:57 bcik volumio[15845]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 16 17:23:57 bcik volumio[15845]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 16 17:23:57 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:57 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:57 bcik volumio[15845]: info: Starting MyVolumio Remote Streaming Endpoints Oct 16 17:23:57 bcik volumio[15845]: info: MyVolumio login type: Token Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 16 17:23:57 bcik volumio[15845]: info: Streaming services startup Oct 16 17:23:57 bcik volumio[15845]: info: Starting Streaming Daemon Oct 16 17:23:57 bcik sudo[16115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:23:57 bcik sudo[16115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:57 bcik volumio[15845]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 16 17:23:57 bcik sudo[16115]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:57 bcik volumio[15845]: error: Cannot start Volumio Streaming Daemon Oct 16 17:23:57 bcik volumio[15845]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:23:57 bcik volumio[15845]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:23:57 bcik sudo[16122]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:23:57 bcik sudo[16122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:57 bcik sudo[16124]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:23:57 bcik sudo[16124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:57 bcik sudo[16122]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:57 bcik sudo[16124]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:57 bcik sudo[16129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 17:23:57 bcik sudo[16129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:57 bcik sudo[16129]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:57 bcik volumio[15845]: info: Upmpdcli Daemon Started Oct 16 17:23:57 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:57 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:57 bcik volumio[15845]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 16 17:23:59 bcik volumio[15845]: info: MyVolumio token set successfully Oct 16 17:23:59 bcik volumio[15845]: info: MYVOLUMIO: Adding device Oct 16 17:23:59 bcik volumio[15845]: info: MYVOLUMIO: Evaluating Server Oct 16 17:23:59 bcik volumio[15845]: info: MyVolumio status changed Oct 16 17:23:59 bcik volumio[15845]: info: Streaming services startup Oct 16 17:23:59 bcik volumio[15845]: info: Starting Streaming Daemon Oct 16 17:23:59 bcik volumio[15845]: info: Removing browser output: myVolumio user plan is not superstar Oct 16 17:23:59 bcik volumio[15845]: info: Removing audio output: Oct 16 17:23:59 bcik volumio[15845]: info: Stoppping Tunnel 1 Oct 16 17:23:59 bcik sudo[16152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:23:59 bcik sudo[16152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:59 bcik sudo[16154]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 16 17:23:59 bcik sudo[16154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:59 bcik sudo[16152]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:59 bcik volumio[15845]: error: Cannot start Volumio Streaming Daemon Oct 16 17:23:59 bcik volumio[15845]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:23:59 bcik volumio[15845]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 17:23:59 bcik sudo[16154]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:59 bcik volumio[15845]: info: Remote SSH Stopped Oct 16 17:23:59 bcik volumio[15845]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:23:59 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:59 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:59 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:59 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 107. Oct 16 17:23:59 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:59 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:59 bcik go-librespot[16157]: go-librespot daemon starting... Oct 16 17:23:59 bcik go-librespot[16158]: time="2026-10-16T17:23:59+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:59 bcik go-librespot[16158]: time="2026-10-16T17:23:59+02:00" level=debug msg="app state loaded" Oct 16 17:23:59 bcik go-librespot[16158]: time="2026-10-16T17:23:59+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:59 bcik volumio[15845]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:23:59 bcik go-librespot[16158]: time="2026-10-16T17:23:59+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:23:59 bcik go-librespot[16158]: time="2026-10-16T17:23:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:23:59 bcik go-librespot[16158]: time="2026-10-16T17:23:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:23:59 bcik go-librespot[16158]: time="2026-10-16T17:23:59+02:00" level=info msg="zeroconf server listening on port 33803" Oct 16 17:24:00 bcik go-librespot[16158]: time="2026-10-16T17:24:00+02:00" level=debug msg="obtained new client token: AAFYJoJqynKXZC333wlHvS5h8H9X/9VpKfjxwJI/hZ8E3ETMZPFa1EISSUupC4Of4alqUyHXlgzxLdQIEWgrpz/MZ6tMe5p9aZrK/3BJxiPX+/PgC3EXg3FyMTJ2K0deExstfOUjtP8J1+gsu+oJuu8HC+uwY5SKKMVX7/L4vFh0jUqjWbFzVtj2WZyAYUEsL7GjQOyVKO/PUfbqX2WRnp0h1UC4rXNq6LwtIs2vz7x7oAGuaPfI//I=" Oct 16 17:24:00 bcik go-librespot[16158]: time="2026-10-16T17:24:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:24:00 bcik go-librespot[16158]: time="2026-10-16T17:24:00+02:00" level=debug msg="completed keyexchange" Oct 16 17:24:00 bcik go-librespot[16158]: time="2026-10-16T17:24:00+02:00" level=debug msg="completed challenge" Oct 16 17:24:00 bcik go-librespot[16158]: time="2026-10-16T17:24:00+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:24:00 bcik go-librespot[16158]: time="2026-10-16T17:24:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:24:00 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:24:00 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:24:00 bcik volumio[15845]: info: Updating MyVolumio device info Oct 16 17:24:00 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:00 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:00 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:00 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:00 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:01 bcik volumio[15845]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:24:03 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 108. Oct 16 17:24:03 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:03 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:03 bcik go-librespot[16167]: go-librespot daemon starting... Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="app state loaded" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=info msg="zeroconf server listening on port 41089" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="obtained new client token: AAG/3g+jO+NP9JRspnrbpAmEMrkmfZRAIWsbyzfcwa5nfAkuNZCW5sQs5isDeEjoo1Dn7FudaKhbKvPDP7PQy62rogoDGqiTan9I3QdOnpLHMkFgJcaPVm9ZKPW2SJ5b9uSopgW9uTvyfJQArgn9hmrx8QZCLkDNrbqV/3IFDQMlfHet6+oOVjyZE8tyysUBxTGuQavqkrBpL+hM/yRZ30W2oJpbsUVqTI425jw2a8zbWRtEHl0idpU=" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="completed keyexchange" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=debug msg="completed challenge" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:24:03 bcik go-librespot[16168]: time="2026-10-16T17:24:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:24:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:24:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:24:03 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:03 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:03 bcik volumio[15845]: info: MYVOLUMIO: Adding device Oct 16 17:24:03 bcik volumio[15845]: info: MYVOLUMIO: Evaluating Server Oct 16 17:24:04 bcik volumio[15845]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:24:04 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:04 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:04 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:04 bcik volumio[15845]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:24:05 bcik volumio[15845]: info: Updating MyVolumio device info Oct 16 17:24:05 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:05 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:05 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:05 bcik volumio[15845]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:24:06 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:06 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:06 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 109. Oct 16 17:24:06 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:06 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:06 bcik go-librespot[16196]: go-librespot daemon starting... Oct 16 17:24:06 bcik go-librespot[16197]: time="2026-10-16T17:24:06+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:24:06 bcik go-librespot[16197]: time="2026-10-16T17:24:06+02:00" level=debug msg="app state loaded" Oct 16 17:24:06 bcik go-librespot[16197]: time="2026-10-16T17:24:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:24:06 bcik go-librespot[16197]: time="2026-10-16T17:24: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-gew1.spotify.com:80]" Oct 16 17:24:06 bcik go-librespot[16197]: time="2026-10-16T17:24:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:24:06 bcik go-librespot[16197]: time="2026-10-16T17:24:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:24:06 bcik go-librespot[16197]: time="2026-10-16T17:24:06+02:00" level=info msg="zeroconf server listening on port 37721" Oct 16 17:24:07 bcik go-librespot[16197]: time="2026-10-16T17:24:07+02:00" level=debug msg="obtained new client token: AAE0Z6XubXs9zh+ZK45uRk0QaR5iMNJgSDMSq2oxafOBxHNBwvcuQrlI7rdjdukm4/kXWSjfAt4qgowN2uPP7kvpiiIZn5guVIfH6BmCJVp2OXuBR4B6ZrwJ+5bkZJ5Zu/DXLgflsOAy3ib+Bi+XpIHz+jMORz8Gty34rtFPgz//abguPbP795daNDjuYQWDLpEalo/8wzdfirbOI6aiKkCQpsssTVXaLa9x/OhOBziIHHAVrpuB" Oct 16 17:24:07 bcik go-librespot[16197]: time="2026-10-16T17:24:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:24:07 bcik go-librespot[16197]: time="2026-10-16T17:24:07+02:00" level=debug msg="completed keyexchange" Oct 16 17:24:07 bcik go-librespot[16197]: time="2026-10-16T17:24:07+02:00" level=debug msg="completed challenge" Oct 16 17:24:07 bcik go-librespot[16197]: time="2026-10-16T17:24:07+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:24:07 bcik go-librespot[16197]: time="2026-10-16T17:24:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:24:07 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:24:07 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:24:09 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:09 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:10 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 110. Oct 16 17:24:10 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:10 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:10 bcik go-librespot[16220]: go-librespot daemon starting... Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=debug msg="app state loaded" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=info msg="zeroconf server listening on port 35459" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=debug msg="obtained new client token: AAEGfmtvXAdhpUFr0fntdd16LZszSft7YhbkZZjzvm2RoCBq7CZWky8vVQAIHVk2HknsGjJhNjaos5OWdCFh0nsCqWrRGk7st9GbwF5ZBz0dcjYvO8Q2z29bUj9kOjdxO1K6G0op7SgwL4tdpgTd4gfRtNXoE0KQlQpWPsuH+j1P+QS9AF3GtFeglFVfc4BYv3O8kkMqIpAbJxT1i31DdjicwfI2ndMlC2oEyLa/0LCRu0OZy2Kuw1s=" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=debug msg="completed keyexchange" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=debug msg="completed challenge" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:24:10 bcik go-librespot[16221]: time="2026-10-16T17:24:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:24:10 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:24:10 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:24:12 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 17:24:12 bcik volumio[15845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 16 17:24:12 bcik volumio[15845]: info: CoreCommandRouter::volumioGetState Oct 16 17:24:12 bcik volumio[15845]: info: CorePlayQueue::getTrack 0 Oct 16 17:24:12 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:12 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:14 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 111. Oct 16 17:24:14 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:14 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:14 bcik go-librespot[16230]: go-librespot daemon starting... Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="app state loaded" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=info msg="zeroconf server listening on port 43967" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="obtained new client token: AAGRWp3vG48t67IrADtdZICzmRX5k53Kt8fEO7u8uAhy7epNsfB3mI+sgIpPjSlZO11ur4aseWxdbiM0G+uvNiUx9+0RGrecRUTgzx4/9TXDUHxV9DR4fVeKoTafPBW6gp6o8uXrSfBa8XgjEsyYeiQO6fPlp8Z3byCbvMGxHjnUoU/AFiShpfMrHhRId+hhwC2g/bu6Te5qDOS+9w6xSLd+qMDxJsWYHwnFeTzK7V4GG5u5zEIg" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="completed keyexchange" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=debug msg="completed challenge" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:24:14 bcik go-librespot[16231]: time="2026-10-16T17:24:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:24:14 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:24:14 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:24:15 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:15 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::volumioGetBrowseSources Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:24:17 bcik volumio[15845]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 16 17:24:17 bcik volumio[15845]: info: Completed starting MyVolumio Plugin Oct 16 17:24:17 bcik volumio[15845]: [Metrics] CommandRouter: 30s 575.38ms Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::volumiosetStartupVolume Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::Close All Modals sent Oct 16 17:24:17 bcik volumio[15845]: info: CoreCommandRouter::Close All Modals sent Oct 16 17:24:17 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 112. Oct 16 17:24:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:17 bcik go-librespot[16257]: go-librespot daemon starting... Oct 16 17:24:17 bcik systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 16 17:24:17 bcik go-librespot[16258]: time="2026-10-16T17:24:17+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:24:17 bcik go-librespot[16258]: time="2026-10-16T17:24:17+02:00" level=debug msg="app state loaded" Oct 16 17:24:17 bcik go-librespot[16258]: time="2026-10-16T17:24:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:24:18 bcik systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 16 17:24:18 bcik systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=info msg="zeroconf server listening on port 45853" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=debug msg="obtained new client token: AAGEniC3pPyzOnE5Zu9rsg6yYXXvgH7shwGAnI30mcRd8FZd9rev1S3N/9O/JYmbFlJWLx3BI9v0PbnszZmUuEn4yQQuUhrTkTpts5aMXv2uZG7CLfppMjAedB0fXIk4gmKQSF27gOQqL917noLQbJzhEG+oIo3BcLiIzW6Hx7ZrGEyWbVkK5ZokNAsVej939ezAswRvLZGcdwZmwZDXP+YfD7RYwUoCPQuoldEkvZyu/xnWEkao" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=debug msg="completed keyexchange" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=debug msg="completed challenge" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:24:18 bcik go-librespot[16258]: time="2026-10-16T17:24:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:24:18 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:24:18 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 17:24:18 bcik volumio-remote-updater[9031]: Test mode disabled Oct 16 17:24:18 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 16 17:24:18 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 16 17:24:18 bcik volumio[15845]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 16 17:24:18 bcik volumio[15845]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 16 17:24:18 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:18 bcik volumio[15845]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:21 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Oct 16 17:24:21 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:21 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:24:21 bcik go-librespot[16296]: go-librespot daemon starting... Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="app state loaded" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=info msg="zeroconf server listening on port 33915" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="obtained new client token: AAFzTOUreDoS2wLW8W5dqZPcLMu6ubV0vgQACIBfcq+aZTIG1IjypJk8QQFO7P3C0/Siv5+bo44miGcofVHptogaPccn5ebnZwOzBOG/onQ/EADsJ+z0U2srffR2T448swT8e8NCIqTUTa2WtiHDfdMDyiDcyxqxsN4ULraOM+Y30goQBI9QCVn2ZtxjUx+QTvIr/mVljQb/+0aIWXJBOmBzFrUDwRo+iJf3qhCtcwlcBS1TT9lovNQ=" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="completed keyexchange" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="completed challenge" Oct 16 17:24:21 bcik volumio[15845]: info: Initializing connection to go-librespot Websocket Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=debug msg="new websocket client" Oct 16 17:24:21 bcik volumio[15845]: info: Connection to go-librespot Websocket established Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:24:21 bcik go-librespot[16297]: time="2026-10-16T17:24:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:24:21 bcik volumio[15845]: info: Connection to go-librespot Websocket closed Oct 16 17:24:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:24:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:24:24 bcik volumio[15845]: info: BOOT COMPLETED Oct 16 17:24:24 bcik volumio[15845]: info: Getting Spotify volume Oct 16 17:24:24 bcik volumio[15845]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:24:24 bcik volumio[15845]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:24:24 bcik volumio[15845]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 16 17:24:24 bcik volumio[15845]: errno: -111, Oct 16 17:24:24 bcik volumio[15845]: code: 'ECONNREFUSED', Oct 16 17:24:24 bcik volumio[15845]: syscall: 'connect', Oct 16 17:24:24 bcik volumio[15845]: address: '127.0.0.1', Oct 16 17:24:24 bcik volumio[15845]: port: 9879, Oct 16 17:24:24 bcik volumio[15845]: response: undefined Oct 16 17:24:24 bcik volumio[15845]: } Oct 16 17:24:24 bcik volumio[15845]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:24:24 bcik sudo[16320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 17:23' Oct 16 17:24:24 bcik sudo[16320]: 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"