Aug 31 15:57:00 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Aug 31 15:57:00 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:00 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:00 bcik go-librespot[27620]: go-librespot daemon starting... Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="app state loaded" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="zeroconf server listening on port 35253" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="obtained new client token: AAEcdmLBeXc3aSlyGxaoHhTqdKTYbypjv9oOyKwkMlqlAbwpAtSk3RPBwz2+bxVXbyI+Uwq0y2O0MpeQjMIrUQJxuYPqKGwriPgBdakvTr2+koko+8G7rT1gdeHDKl6G9O7yICCdDPfcauKrsY/j0HM8+uRUMj3uepSsA2FAXifHSXdh94+Yks5N4PidaPgeJcTdwnnDd/WhvHRhFKjfd3l8F+G1nOGBrLNXJlfkgLbE+HCpUzmX" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=debug msg="completed challenge" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:00 bcik go-librespot[27621]: time="2026-08-31T15:57:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:00 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:00 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:00 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:00 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:01 bcik volumio[27282]: info: MYVOLUMIO: Adding device Aug 31 15:57:01 bcik volumio[27282]: info: MYVOLUMIO: Evaluating Server Aug 31 15:57:01 bcik volumio[27282]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:57:01 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:01 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:01 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:02 bcik volumio[27282]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:57:02 bcik volumio[27282]: info: Updating MyVolumio device info Aug 31 15:57:02 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:02 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:02 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:03 bcik volumio[27282]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:57:03 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Aug 31 15:57:03 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:03 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:03 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:03 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:03 bcik go-librespot[27650]: go-librespot daemon starting... Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="app state loaded" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="zeroconf server listening on port 41717" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="obtained new client token: AAGrkTnwPySp82PhTbynBiOaTx+OgJky+k+SDuNhfB5InLxJMktcpZk8/1Sl7ViZNC3nNWxoW+vLI4sYjppijsrYf9stOR/+3ridkqGbuT+kCa1fhqng4dffoOIwZ1HfvGA+ZY01gcLILjnWHjAFhoHNF5d+1iQ20ftHXBuEh7IyRrUwIGrithVFVX+M8SA1M45pst/DzgRIilDCSQGaFE1qe8fUNVzvu8pdu6QevtV0HqU3sDAqUfM=" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=debug msg="completed challenge" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:03 bcik go-librespot[27651]: time="2026-08-31T15:57:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:06 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:06 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:07 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Aug 31 15:57:07 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:07 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:07 bcik go-librespot[27676]: go-librespot daemon starting... Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="app state loaded" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="zeroconf server listening on port 46227" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="obtained new client token: AAE+AiIEssasqjSws3AY6rOdux7Mr19Nq/P78ehBx0NTKe8GN1bfB/hTEhKxU4dBHQvKyVw/kJ/AOUNAXjVRpS7divUSAWGude8Gyprd/nC7zO7sB6kMfh50D3r+0V6xowcFDa4lAPOZlnpxzeZ95atQPII4HF8L9Tw8DweqiJbJpK4dE7LtYGS8FR/i21ESQqiRMNvztm/OdYL4buCo7z9Xqv7Tj1U2CSqZ+/wuZRNqauffRP5M" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=debug msg="completed challenge" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:07 bcik go-librespot[27677]: time="2026-08-31T15:57:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:07 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:07 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:09 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 15:57:09 bcik volumio[27282]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 15:57:09 bcik volumio[27282]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:09 bcik volumio[27282]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:09 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:09 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:10 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Aug 31 15:57:10 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:10 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:10 bcik go-librespot[27686]: go-librespot daemon starting... Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="app state loaded" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57: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]" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57: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]" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57: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]" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="zeroconf server listening on port 41911" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="obtained new client token: AAEFGW/elGDVuivcGamINdmA0nIdMUqgfwfpFEgvOaW4npUPxvEWKKA4WDem7ltPiNnEkQ39ORRC5EgvH1zmyi1sQhefeGD2avFKgTS6JeXu+DkOyv5Klde59ifkn9eeoyydKoHzT+5u3nJejE/U/5aWTF6OZHnyYZf/Qeni2W87U5U8vfYZ4GnE0OkDEpxFep6p5tSaZ2v42klX2LK7f7RZrFh+Z+ASEtVprCkROmFC3IiXL5FLq1M=" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=debug msg="completed challenge" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:10 bcik go-librespot[27687]: time="2026-08-31T15:57:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:10 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:10 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:12 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:12 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:14 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Aug 31 15:57:14 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:14 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:14 bcik go-librespot[27696]: go-librespot daemon starting... Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="app state loaded" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="zeroconf server listening on port 44795" Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="obtained new client token: AAHMHk0hV+wz9StvuXfgRy5WJzlu68EaSXxmqY8fDPfGkJqTz/C56JxhMdWj6Ye0XmeSeJjQDxqL3us6bX6DH5n9M58sK7itBVtRkDwaAhqBiuhiojdpxKRjIU80tjAo0SXW5fOrqcNuwIR2qI5MEvJpI6ul2cFtd4UQbxpkv0/qGhN3Pc8DpieP+tZeRWoWllhOLPKUdOuVfAiIRlnzzSsfEc6CDuvIybxzY00hKL+bydfw46tU" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=debug msg="completed challenge" Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:14 bcik volumio[27282]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 15:57:14 bcik volumio[27282]: info: Completed starting MyVolumio Plugin Aug 31 15:57:14 bcik volumio[27282]: [Metrics] CommandRouter: 30s 712.62ms Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:57:14 bcik volumio[27282]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:57:14 bcik go-librespot[27697]: time="2026-08-31T15:57:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:14 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:14 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 15:57:15 bcik volumio-remote-updater[962]: Test mode disabled Aug 31 15:57:15 bcik volumio-remote-updater[962]: Alpha mode disabled Aug 31 15:57:15 bcik volumio-remote-updater[962]: Alpha legacy test mode disabled Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 15:57:15 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:15 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:15 bcik volumio[27282]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 15:57:15 bcik volumio[27282]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 15:57:17 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Aug 31 15:57:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:17 bcik go-librespot[27727]: go-librespot daemon starting... Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="app state loaded" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="zeroconf server listening on port 41979" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="obtained new client token: AAEl4DWxZZ1Hm2PIxn7BKB13IaKfpEXcZVsEOFohXs04QePIiB+yYh32pxIdDfx8zMOkNCu85a3BxZ9jOHSNvmI9ie7x+ZLgKK0pOqh5ByINEHqzo4eIuKcqPYqPd/1t1m2orqsUA19R4Zug7aoTdwkaNwcoL1j/HK7D8AJEA911zl0mMhKnxAOmRkhun6RzRcm98od/Tx2nqZ11/PVqzrDWFp37oVQnzYIQT3zPTAQVJ1CsepudS9Y=" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=debug msg="completed challenge" Aug 31 15:57:17 bcik go-librespot[27728]: time="2026-08-31T15:57:17+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:18 bcik go-librespot[27728]: time="2026-08-31T15:57:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:18 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:18 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:18 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:18 bcik volumio[27282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:21 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Aug 31 15:57:21 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:21 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:21 bcik go-librespot[27737]: go-librespot daemon starting... Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="app state loaded" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57: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]" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57: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]" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57: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]" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="zeroconf server listening on port 46017" Aug 31 15:57:21 bcik volumio[27282]: info: BOOT COMPLETED Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="obtained new client token: AAHwtW4XHgpb2jXOceN97L7fK6wz+YKJ4iayiLBK/sXkMXZmfhJWIu0+ht20j/wZ63H8bRQVQ1aJRShf+I4+4hNy9Z3/I6Htju6DeThNOPr+Dyc05Ii/qBexKQyhOL1rPKxVzAJE2c5AKfHHu9e+NxYeT926zVpElFq2228HSbCWAyfYImeTKdwtQpQLLlhOzlxu8+VN+tFZtqCX9x/MCoU2FXajkSKMLOTgA1ksKxl6sR1vR1dbl9Y=" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:21 bcik volumio[27282]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="new websocket client" Aug 31 15:57:21 bcik volumio[27282]: info: Connection to go-librespot Websocket established Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=debug msg="completed challenge" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:21 bcik go-librespot[27738]: time="2026-08-31T15:57:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:21 bcik volumio[27282]: info: Connection to go-librespot Websocket closed Aug 31 15:57:24 bcik volumio[27282]: info: Getting Spotify volume Aug 31 15:57:24 bcik volumio[27282]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:24 bcik volumio[27282]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:24 bcik volumio[27282]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 15:57:24 bcik volumio[27282]: errno: -111, Aug 31 15:57:24 bcik volumio[27282]: code: 'ECONNREFUSED', Aug 31 15:57:24 bcik volumio[27282]: syscall: 'connect', Aug 31 15:57:24 bcik volumio[27282]: address: '127.0.0.1', Aug 31 15:57:24 bcik volumio[27282]: port: 9879, Aug 31 15:57:24 bcik volumio[27282]: response: undefined Aug 31 15:57:24 bcik volumio[27282]: } Aug 31 15:57:24 bcik volumio[27282]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:24 bcik sudo[27777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:56' Aug 31 15:57:24 bcik sudo[27777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:24 bcik sudo[27777]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Aug 31 15:57:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:24 bcik volumio-remote-updater[962]: [2026-08-31 15:57:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 15:57:24 bcik volumio-remote-updater[962]: [2026-08-31 15:57:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 15:57:24 bcik volumio5-onboarding[1666]: time=2026-08-31T15:57:24.773+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 15:57:24 bcik volumio5-onboarding[1666]: time=2026-08-31T15:57:24.773+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 15:57:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:24 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:24 bcik go-librespot[27782]: go-librespot daemon starting... Aug 31 15:57:24 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 15:57:24 bcik systemd[1]: volumio.service: Consumed 6.624s CPU time. Aug 31 15:57:24 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="app state loaded" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:24 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=info msg="zeroconf server listening on port 35229" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="obtained new client token: AAH0mR2/qwQZwJxgDlMIfrrbO2kEoeyZ7n5NQdKgylU7r8hIURuYLIvx2E2T7VmBu2p4p5N4TsADkmNHuwQq0LteXnMdAgFIMZy72vpDzhN7HcyPjGLMaBSt+ZYyjSOfsJTzYBB+qwMxiDdZiHrTWWGQ7YfX2vLwtpk+NFFaT0AtOjiKPGgtnfLIewkU/NuRIE4z+CzjJ8DeBOWSiWz31/J7SY+i0pXp+l4PW/mnmqCPHlHU/944afE=" Aug 31 15:57:24 bcik go-librespot[27783]: time="2026-08-31T15:57:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:25 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 242. Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=debug msg="completed challenge" Aug 31 15:57:25 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:57:25 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 15:57:25 bcik systemd[1]: volumio.service: Consumed 6.624s CPU time. Aug 31 15:57:25 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 15:57:25 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:25 bcik go-librespot[27783]: time="2026-08-31T15:57:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:25 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:25 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: ----- Volumio3 ---- Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: ----- System startup ---- Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: MYVOLUMIO Environment detected Aug 31 15:57:25 bcik volumio[27798]: info: Plugin folders cleanup Aug 31 15:57:25 bcik volumio[27798]: info: Scanning into folder /volumio/app/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category audio_interface Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category miscellanea Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category music_service Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category plugins.json Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category system_controller Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category user_interface Aug 31 15:57:25 bcik volumio[27798]: info: Scanning into folder /data/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Scanning category music_service Aug 31 15:57:25 bcik volumio[27798]: info: Plugin folders cleanup completed Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: ----- Core plugins startup ---- Aug 31 15:57:25 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Adding plugin upnp to MyMusic Plugins Aug 31 15:57:25 bcik volumio[27798]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 15:57:25 bcik volumio[27798]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugins from folder /data/plugins/ Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "system"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "appearance"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "network"... Aug 31 15:57:25 bcik volumio[27798]: info: Refreshing Cached IP Addresses Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "services"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "volumio5onboarding"... Aug 31 15:57:25 bcik sudo[27827]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:57:25 bcik sudo[27829]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:57:25 bcik sudo[27827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:25 bcik sudo[27829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:25 bcik sudo[27827]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:25 bcik sudo[27829]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "alsa_controller"... Aug 31 15:57:25 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "wizard"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "networkfs"... Aug 31 15:57:25 bcik volumio[27798]: info: Starting Udev Watcher for removable devices Aug 31 15:57:25 bcik volumio[27798]: info: Ignoring mount for partition: boot Aug 31 15:57:25 bcik volumio[27798]: info: Ignoring mount for partition: volumio Aug 31 15:57:25 bcik volumio[27798]: info: Ignoring mount for partition: volumio_data Aug 31 15:57:25 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "volumio_command_line_client"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "upnp"... Aug 31 15:57:25 bcik volumio[27798]: info: [1788184645827] Starting Upmpd Daemon Aug 31 15:57:25 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "my_music"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "mpd"... Aug 31 15:57:25 bcik volumio[27798]: info: Loading plugin "upnp_browser"... Aug 31 15:57:26 bcik volumio[27798]: info: Starting UPNP Browser Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "alarm-clock"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "airplay_emulation"... Aug 31 15:57:26 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "last_100"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "webradio"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "i2s_dacs"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "volumiodiscovery"... Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik volumio[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik volumio[27798]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 15:57:26 bcik volumio[27798]: info: Discovery: Started advertising with name: Bącik Aug 31 15:57:26 bcik node[27798]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik node[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik node[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik node[27798]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:26 bcik node[27798]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:26 bcik node[27798]: *** WARNING *** For more information see Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "spop"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "outputs"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "albumart"... Aug 31 15:57:26 bcik volumio[27798]: info: Plugin example_plugin is not enabled Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "inputs"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "updater_comm"... Aug 31 15:57:26 bcik volumio[27798]: info: Plugin mpdemulation is not enabled Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "rest_api"... Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "websocket"... Aug 31 15:57:26 bcik volumio[27798]: info: Starting Socket.io Server version 1.7.4 Aug 31 15:57:26 bcik volumio[27798]: info: Loading plugin "radio_browser"... Aug 31 15:57:26 bcik volumio[27859]: Forking 3 albumart workers Aug 31 15:57:26 bcik volumio[27798]: info: Loading i18n strings for locale pl Aug 31 15:57:26 bcik volumio[27798]: Updating browse sources language Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::initPlayerControls Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: Express server listening on port 3000 Aug 31 15:57:26 bcik volumio[27798]: [Metrics] WebUI: 1s 290.01ms Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::resetVolumioState Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::getcurrentVolume Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:57:26 bcik volumio[27798]: info: Volumio Network Manager: Network status updated: 1 Aug 31 15:57:26 bcik volumio[27798]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: Reloading queue from file Aug 31 15:57:26 bcik volumio[27798]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::setRepeat false single undefined Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::setRandom false Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 15:57:26 bcik volumio[27798]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 15:57:26 bcik volumio[27798]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 15:57:26 bcik volumio[27798]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:26 bcik volumio[27798]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::updateTrackBlock Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrackBlock Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:57:26 bcik volumio[27798]: info: Setting Device type: Raspberry PI Aug 31 15:57:26 bcik volumio[27798]: info: Completed loading Core Plugins Aug 31 15:57:26 bcik volumio[27798]: info: Preparing to generate the ALSA configuration file Aug 31 15:57:26 bcik volumio[27798]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:57:26 bcik volumio[27798]: info: CoreStateMachine::pushState Aug 31 15:57:26 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:26 bcik volumio[27798]: info: Asound.conf file unchanged, so no further update is needed Aug 31 15:57:26 bcik volumio[27798]: info: Output device has changed, restarting MPD Aug 31 15:57:26 bcik volumio[27798]: info: Output device has changed, restarting Shairport Sync Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik sudo[27914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:57:26 bcik sudo[27914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:26 bcik volumio[27798]: info: ___________ START PLUGINS ___________ Aug 31 15:57:26 bcik sudo[27914]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik sudo[27916]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:57:26 bcik sudo[27916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: ControllerMpd::onStart: Initializing MPD Aug 31 15:57:26 bcik volumio[27798]: info: Creating MPD Configuration file Aug 31 15:57:26 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 15:57:26 bcik sudo[27924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 15:57:26 bcik sudo[27924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646768] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik sudo[27926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:57:26 bcik volumio[27798]: info: UPNP Browser: Client initialized successfully Aug 31 15:57:26 bcik sudo[27926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:57:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik sudo[27926]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik sudo[27929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:57:26 bcik sudo[27929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:26 bcik volumio[27798]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:57:26 bcik volumio[27798]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646811] CoreMusicLibrary::Adding element Last_100 Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646811] CoreMusicLibrary::Adding element Webradio Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:26 bcik sudo[27924]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik volumio[27798]: info: Initializing BBC Radios Aug 31 15:57:26 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:57:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:57:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:57:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:57:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:26 bcik volumio[27798]: info: Creating Spotify config file Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:26 bcik sudo[27946]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 15:57:26 bcik sudo[27946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 15:57:26 bcik volumio[27870]: Starting albumart workers Aug 31 15:57:26 bcik sudo[27946]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:26 bcik volumio[27869]: Starting albumart workers Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:26 bcik volumio[27798]: info: [1788184646970] CoreMusicLibrary::Adding element Radio Browser Aug 31 15:57:26 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:26 bcik volumio[27798]: Cannot find translation for source Radio Browser Aug 31 15:57:26 bcik volumio[27798]: info: Volumio Calling Home Aug 31 15:57:27 bcik volumio[27798]: info: MPD Permissions set Aug 31 15:57:27 bcik volumio[27798]: info: MPD Permissions set Aug 31 15:57:27 bcik volumio[27798]: info: Spotify config file written Aug 31 15:57:27 bcik sudo[27969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 15:57:27 bcik sudo[27969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik volumio[27798]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:27 bcik volumio[27798]: info: No need to fix Spotify hosts Aug 31 15:57:27 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:27 bcik sudo[27969]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik go-librespot[27972]: go-librespot daemon starting... Aug 31 15:57:27 bcik volumio[27871]: Starting albumart workers Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="app state loaded" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:27 bcik volumio[27798]: info: Volumio called home Aug 31 15:57:27 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:27 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:27 bcik volumio[27798]: info: Starting Shairport Sync Aug 31 15:57:27 bcik sudo[27997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:27 bcik sudo[27997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik sudo[27998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:27 bcik sudo[27998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik sudo[28000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:27 bcik sudo[28000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:27 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="zeroconf server listening on port 46431" Aug 31 15:57:27 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:57:27 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:57:27 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:27 bcik systemd[1]: shairport-sync.service: Consumed 1.552s CPU time. Aug 31 15:57:27 bcik volumio[27798]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 15:57:27 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:27 bcik sudo[27997]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:57:27 bcik sudo[27998]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: Found device Bącik Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:27 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:27 bcik sudo[28000]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:57:27 bcik volumio[27798]: info: Discovery: Found device Bącik Aug 31 15:57:27 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:27 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:27 bcik volumio[27798]: info: Shairport-Sync Started Aug 31 15:57:27 bcik volumio[27798]: Error adding Membership: Error: addMembership EINVAL Aug 31 15:57:27 bcik volumio[27798]: info: Shairport-Sync Started Aug 31 15:57:27 bcik volumio[27798]: info: Shairport-Sync Started Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="obtained new client token: AAGfZy1o8tYzJ07Aw/4uVs9hK2ZlRKBFYuGm8qjkkvKlBcnUxm716i3pxHvZS+fd5OvJgDJ+nyyYClOWKRNoVCIE1PFsQNJQnGysqrIqo6qe93ulan02qqNslJ3d3r+JuPaMzRhlYDPiS4ZrGs1bihKH92F4oTQHuhrNdT/unkLgjqJ1t3Covmlg1BWlgFLZhsTaNrTE7/hvA321JjEeKeFgOYcNtQVZ/4M9+MA0nmYiqzSPVMb0" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=debug msg="completed challenge" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:27 bcik go-librespot[27988]: time="2026-08-31T15:57:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:27 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:27 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:27 bcik mpd[27958]: 2026-08-31T15:57:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 15:57:27 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 15:57:27 bcik sudo[27929]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik sudo[27916]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:27 bcik volumio[27798]: info: Completed starting Core Plugins Aug 31 15:57:27 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:27 bcik volumio[27798]: info: ----- MyVolumio plugins startup ---- Aug 31 15:57:27 bcik volumio[27798]: info: ------------------------------------------- Aug 31 15:57:27 bcik volumio[27798]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 15:57:27 bcik volumio[27798]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:57:27 bcik volumio[27798]: assert.ok(self.idling) Aug 31 15:57:27 bcik volumio[27798]: error: The expression evaluated to a falsy value: Aug 31 15:57:27 bcik volumio[27798]: assert.ok(self.idling) Aug 31 15:57:27 bcik volumio[27798]: error: updateQueue error: null Aug 31 15:57:27 bcik volumio[27798]: info: MPD running with PID27958 Aug 31 15:57:27 bcik volumio[27798]: ,establishing connection Aug 31 15:57:27 bcik volumio[27798]: error: updateQueue error: null Aug 31 15:57:29 bcik volumio-remote-updater[962]: [2026-08-31 15:57:29] [connect] Successful connection Aug 31 15:57:29 bcik volumio-remote-updater[962]: [2026-08-31 15:57:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788184649 101 Aug 31 15:57:29 bcik volumio[27798]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Aug 31 15:57:30 bcik volumio[27798]: info: go-librespot daemon successfully initialized Aug 31 15:57:30 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Aug 31 15:57:30 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:30 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:30 bcik go-librespot[28036]: go-librespot daemon starting... Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="app state loaded" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57: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-gew1.spotify.com:80]" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="zeroconf server listening on port 37471" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="obtained new client token: AAFY4jBB04sOG0C+fQ9M5HPXtjXxk7IyGtNlOZcDBBM86Y2N/qTcXNM5in36i5qnzN6ctRwLcURSUCvOKk2t+PH1GIkne0S+2qLTZv2s/va3HKVjn6AD9/4DB/auyASe9i2Psg7wfVXxYMSN0OUzDEk50lb1Q05nTWBsqNh3jgjodFGZ5CLvU5+hQ7nWEDJonQPcceWLdLRi333oWJPKLogJ7tHXVsX6fjQUNOeR4lyqB7Z5MKmqck4=" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=debug msg="completed challenge" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:30 bcik go-librespot[28037]: time="2026-08-31T15:57:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:32 bcik volumio[27798]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:57:33 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:33 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:34 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Aug 31 15:57:34 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:34 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:34 bcik go-librespot[28046]: go-librespot daemon starting... Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="app state loaded" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="zeroconf server listening on port 39963" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="obtained new client token: AAG7OarenqOm0L2NUV2a2BtEhro/O+KRUanaZNZb2OWztFkfwmuLIMk8kBh02+/a4sHiWVr6ZG/Cl5+sa5ESOWMj4NMLXTQ93Gr63mzpOsJ+OpAWxXUVCtZaUixq3q8WT73QBX7bMarXYYQrUVBWIOPPNvOgg4CmhubYcgsFefR7K6E+bv6XsDmgbBh80kV0kX/pPgFjgShlmZSt2abrFG7pmuIOzymg4kpvCaEP6i5c6MPM1IAe" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=debug msg="completed challenge" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:34 bcik go-librespot[28047]: time="2026-08-31T15:57:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:34 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:34 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:57:35 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:35 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:35 bcik volumio[27798]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:57:35 bcik volumio[27798]: info: MyVolumio login type: Token Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:57:35 bcik volumio[27798]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:57:36 bcik volumio[27798]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:57:36 bcik volumio[27798]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:57:36 bcik volumio[27798]: info: Streaming services startup Aug 31 15:57:36 bcik volumio[27798]: info: Starting Streaming Daemon Aug 31 15:57:36 bcik sudo[28071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:57:36 bcik sudo[28071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik volumio[27798]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:57:36 bcik sudo[28071]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik sudo[28078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:57:36 bcik sudo[28078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik sudo[28080]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:57:36 bcik sudo[28080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik sudo[28078]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik sudo[28080]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik volumio[27798]: error: Cannot start Volumio Streaming Daemon Aug 31 15:57:36 bcik volumio[27798]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:57:36 bcik volumio[27798]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:57:36 bcik sudo[28084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:57:36 bcik sudo[28084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:36 bcik sudo[28084]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:36 bcik volumio[27798]: info: Upmpdcli Daemon Started Aug 31 15:57:36 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:36 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:36 bcik volumio[27798]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:57:36 bcik volumio[27798]: info: MyVolumio token set successfully Aug 31 15:57:36 bcik volumio[27798]: info: MYVOLUMIO: Adding device Aug 31 15:57:36 bcik volumio[27798]: info: MYVOLUMIO: Evaluating Server Aug 31 15:57:37 bcik volumio[27798]: info: MyVolumio status changed Aug 31 15:57:37 bcik volumio[27798]: info: Streaming services startup Aug 31 15:57:37 bcik volumio[27798]: info: Starting Streaming Daemon Aug 31 15:57:37 bcik volumio[27798]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:57:37 bcik volumio[27798]: info: Removing audio output: Aug 31 15:57:37 bcik volumio[27798]: info: Stoppping Tunnel 1 Aug 31 15:57:37 bcik sudo[28107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:57:37 bcik sudo[28107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:37 bcik sudo[28107]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:37 bcik volumio[27798]: error: Cannot start Volumio Streaming Daemon Aug 31 15:57:37 bcik volumio[27798]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:57:37 bcik volumio[27798]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:57:37 bcik sudo[28110]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:57:37 bcik sudo[28110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57: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. Aug 31 15:57: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. Aug 31 15:57: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. Aug 31 15:57: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. Aug 31 15:57: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. Aug 31 15:57: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. Aug 31 15:57: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. Aug 31 15:57: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. Aug 31 15:57:37 bcik sudo[28110]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:37 bcik volumio[27798]: info: Remote SSH Stopped Aug 31 15:57:37 bcik volumio[27798]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:57:37 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:37 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:37 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Aug 31 15:57:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:37 bcik go-librespot[28112]: go-librespot daemon starting... Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="app state loaded" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57: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]" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57: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]" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57: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]" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="zeroconf server listening on port 46063" Aug 31 15:57:37 bcik volumio[27798]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="obtained new client token: AAGBuh0kjI7SvE/8/K/3bCm/yDxiGlgwGj9wRKhrwYW0cbsinGD1249mWQ+aH6sVLx73jyRCfAEgqzfmrG3KzyVHc02FQ3FwAoMk7EqyV+0u6E5oFlEfjak5shSDQIT2xUuEQMI54eDbld17bGofwDYSnjK4uSIT0CjFN2HDTFGRBrC3DTupSWT9LLcPtmMUYDYUFzBbrThyKnTESWhsLfXpdHe9hWqHj1OWfx669wzRkN9q1WGAvvE=" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=debug msg="completed challenge" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:37 bcik go-librespot[28113]: time="2026-08-31T15:57:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:38 bcik volumio[27798]: info: Updating MyVolumio device info Aug 31 15:57:38 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:38 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:38 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:39 bcik volumio[27798]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:57:39 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:39 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:41 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Aug 31 15:57:41 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:41 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:41 bcik go-librespot[28123]: go-librespot daemon starting... Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="app state loaded" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="zeroconf server listening on port 40297" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="obtained new client token: AAHFh291EqwenVeXMHiG4mPMIks7RajIsWZxJTpBZ5+4v+Bp3SjkvXrKz7qlkPVclltZgNUpQkKyq4QZmkTAjTD6UpzTWOy2UY/2Kflq+MLrwrL3JAUE0brp4yVRFSoUwl4WpouHFRozICvNunaFw4Sy/VmJQ+zbIVhWLFNfyuZIFuJtB/dtmJtfIoNxS8tr6xpVOcW/YvnG3/fTCejOJMPW/TD1pYk8MVZskdQT/G9mXjcX+AdN" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=debug msg="completed challenge" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:41 bcik go-librespot[28124]: time="2026-08-31T15:57:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:41 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:41 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:41 bcik volumio[27798]: info: MYVOLUMIO: Adding device Aug 31 15:57:41 bcik volumio[27798]: info: MYVOLUMIO: Evaluating Server Aug 31 15:57:42 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:42 bcik volumio[27798]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:42 bcik volumio[27798]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:57:42 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:42 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:42 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:42 bcik volumio[27798]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:57:43 bcik volumio[27798]: info: Updating MyVolumio device info Aug 31 15:57:43 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:43 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:43 bcik volumio[27798]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:43 bcik volumio[27798]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:57:44 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Aug 31 15:57:44 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:44 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:44 bcik go-librespot[28151]: go-librespot daemon starting... Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="app state loaded" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=info msg="zeroconf server listening on port 44165" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="obtained new client token: AAHw7t7L3yZCbVW3H25+BIPjzSZPP7USRSfs7+iSq8m+h+4hZ0F7SRDhPdXWC3uNFpRkz6Lb99Au5oyzORumiG71S+xZSQHc1kgHz9IUZQ1u2V/vTObbHvIe+wEfxfmH/5G6p/yKS91wc9uE59wI2uULtp5q5bzFa0KLcX/1GftUZMQ48rEAjXvE3Qbg7zGiXU40f+vTP22KUZi91UU9AY7F7CjMFmTUkua1bqce1FhuXa5s+3AS9nU=" Aug 31 15:57:44 bcik go-librespot[28152]: time="2026-08-31T15:57:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:45 bcik volumio[27798]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:45 bcik go-librespot[28152]: time="2026-08-31T15:57:45+02:00" level=debug msg="new websocket client" Aug 31 15:57:45 bcik volumio[27798]: info: Connection to go-librespot Websocket established Aug 31 15:57:48 bcik volumio[27798]: info: Getting Spotify volume Aug 31 15:57:48 bcik volumio[27798]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 15:57:48 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:48 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:48 bcik volumio[27798]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Aug 31 15:57:48 bcik volumio[27798]: SPOTIFY: SPOTIFY VOLUME undefined Aug 31 15:57:48 bcik volumio[27798]: SPOTIFY: VOLUMIO VOLUME 53 Aug 31 15:57:48 bcik volumio[27798]: info: Aligning Spotify Volume to Volumio Volume Aug 31 15:57:48 bcik volumio[27798]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:48 bcik volumio[27798]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:48 bcik volumio[27798]: info: Setting Spotify Volume from Volumio: 53 Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=debug msg="completed challenge" Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:48 bcik go-librespot[28152]: time="2026-08-31T15:57:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:48 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:48 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:48 bcik volumio[27798]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:48 bcik volumio[27798]: Error: socket hang up Aug 31 15:57:48 bcik volumio[27798]: at connResetException (node:internal/errors:720:14) Aug 31 15:57:48 bcik volumio[27798]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 31 15:57:48 bcik volumio[27798]: at Socket.emit (node:events:526:35) Aug 31 15:57:48 bcik volumio[27798]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 31 15:57:48 bcik volumio[27798]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 31 15:57:48 bcik volumio[27798]: code: 'ECONNRESET', Aug 31 15:57:48 bcik volumio[27798]: response: undefined Aug 31 15:57:48 bcik volumio[27798]: } Aug 31 15:57:48 bcik volumio[27798]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:57:49 bcik sudo[28197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:56' Aug 31 15:57:49 bcik sudo[28197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:49 bcik sudo[28197]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:49 bcik volumio5-onboarding[1666]: time=2026-08-31T15:57:49.414+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 15:57:49 bcik volumio-remote-updater[962]: [2026-08-31 15:57:49] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 15:57:49 bcik volumio-remote-updater[962]: [2026-08-31 15:57:49] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 15:57:49 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:49 bcik volumio5-onboarding[1666]: time=2026-08-31T15:57:49.415+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 15:57:49 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 15:57:49 bcik systemd[1]: volumio.service: Consumed 6.063s CPU time. Aug 31 15:57:49 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:57:49 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:57:49 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 243. Aug 31 15:57:49 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:57:49 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 15:57:49 bcik systemd[1]: volumio.service: Consumed 6.063s CPU time. Aug 31 15:57:49 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 15:57:49 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:57:50 bcik volumio[28216]: info: ------------------------------------------- Aug 31 15:57:50 bcik volumio[28216]: info: ----- Volumio3 ---- Aug 31 15:57:50 bcik volumio[28216]: info: ------------------------------------------- Aug 31 15:57:50 bcik volumio[28216]: info: ----- System startup ---- Aug 31 15:57:50 bcik volumio[28216]: info: ------------------------------------------- Aug 31 15:57:50 bcik volumio[28216]: info: MYVOLUMIO Environment detected Aug 31 15:57:50 bcik volumio[28216]: info: Plugin folders cleanup Aug 31 15:57:50 bcik volumio[28216]: info: Scanning into folder /volumio/app/plugins/ Aug 31 15:57:50 bcik volumio[28216]: info: Scanning category audio_interface Aug 31 15:57:50 bcik volumio[28216]: info: Scanning category miscellanea Aug 31 15:57:50 bcik volumio[28216]: info: Scanning category music_service Aug 31 15:57:50 bcik volumio[28216]: info: Scanning category plugins.json Aug 31 15:57:50 bcik volumio[28216]: info: Scanning category system_controller Aug 31 15:57:50 bcik volumio[28216]: info: Scanning category user_interface Aug 31 15:57:50 bcik volumio[28216]: info: Scanning into folder /data/plugins/ Aug 31 15:57:50 bcik volumio[28216]: info: Scanning category music_service Aug 31 15:57:50 bcik volumio[28216]: info: Plugin folders cleanup completed Aug 31 15:57:50 bcik volumio[28216]: info: ------------------------------------------- Aug 31 15:57:50 bcik volumio[28216]: info: ----- Core plugins startup ---- Aug 31 15:57:50 bcik volumio[28216]: info: ------------------------------------------- Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 15:57:50 bcik volumio[28216]: info: Adding plugin upnp to MyMusic Plugins Aug 31 15:57:50 bcik volumio[28216]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 15:57:50 bcik volumio[28216]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugins from folder /data/plugins/ Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "system"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "appearance"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "network"... Aug 31 15:57:50 bcik volumio[28216]: info: Refreshing Cached IP Addresses Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "services"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "volumio5onboarding"... Aug 31 15:57:50 bcik sudo[28241]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:57:50 bcik sudo[28241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:50 bcik sudo[28243]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:57:50 bcik sudo[28243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "alsa_controller"... Aug 31 15:57:50 bcik sudo[28243]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:50 bcik sudo[28241]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:50 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "wizard"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "networkfs"... Aug 31 15:57:50 bcik volumio[28216]: info: Starting Udev Watcher for removable devices Aug 31 15:57:50 bcik volumio[28216]: info: Ignoring mount for partition: boot Aug 31 15:57:50 bcik volumio[28216]: info: Ignoring mount for partition: volumio Aug 31 15:57:50 bcik volumio[28216]: info: Ignoring mount for partition: volumio_data Aug 31 15:57:50 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "volumio_command_line_client"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "upnp"... Aug 31 15:57:50 bcik volumio[28216]: info: [1788184670562] Starting Upmpd Daemon Aug 31 15:57:50 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "my_music"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "mpd"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "upnp_browser"... Aug 31 15:57:50 bcik volumio[28216]: info: Starting UPNP Browser Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "alarm-clock"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "airplay_emulation"... Aug 31 15:57:50 bcik volumio[28216]: info: Starting Shairport Sync Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "last_100"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "webradio"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "i2s_dacs"... Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "volumiodiscovery"... Aug 31 15:57:50 bcik volumio[28216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:50 bcik volumio[28216]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:50 bcik volumio[28216]: *** WARNING *** For more information see Aug 31 15:57:50 bcik volumio[28216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:50 bcik volumio[28216]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:50 bcik volumio[28216]: *** WARNING *** For more information see Aug 31 15:57:50 bcik node[28216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:50 bcik node[28216]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:50 bcik node[28216]: *** WARNING *** For more information see Aug 31 15:57:50 bcik node[28216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:57:50 bcik node[28216]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:57:50 bcik node[28216]: *** WARNING *** For more information see Aug 31 15:57:50 bcik volumio[28216]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 15:57:50 bcik volumio[28216]: info: Discovery: Started advertising with name: Bącik Aug 31 15:57:50 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:57:50 bcik volumio[28216]: info: Loading plugin "spop"... Aug 31 15:57:51 bcik volumio[28216]: info: Loading plugin "outputs"... Aug 31 15:57:51 bcik volumio[28216]: info: Loading plugin "albumart"... Aug 31 15:57:51 bcik volumio[28216]: info: Plugin example_plugin is not enabled Aug 31 15:57:51 bcik volumio[28216]: info: Loading plugin "inputs"... Aug 31 15:57:51 bcik volumio[28216]: info: Loading plugin "updater_comm"... Aug 31 15:57:51 bcik volumio[28216]: info: Plugin mpdemulation is not enabled Aug 31 15:57:51 bcik volumio[28216]: info: Loading plugin "rest_api"... Aug 31 15:57:51 bcik volumio[28216]: info: Loading plugin "websocket"... Aug 31 15:57:51 bcik volumio[28216]: info: Starting Socket.io Server version 1.7.4 Aug 31 15:57:51 bcik volumio[28216]: info: Loading plugin "radio_browser"... Aug 31 15:57:51 bcik volumio[28273]: Forking 3 albumart workers Aug 31 15:57:51 bcik volumio[28216]: info: Loading i18n strings for locale pl Aug 31 15:57:51 bcik volumio[28216]: Updating browse sources language Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::initPlayerControls Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: Express server listening on port 3000 Aug 31 15:57:51 bcik volumio[28216]: [Metrics] WebUI: 1s 285.53ms Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::resetVolumioState Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::getcurrentVolume Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:57:51 bcik volumio[28216]: info: Volumio Network Manager: Network status updated: 1 Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::pushState Aug 31 15:57:51 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::updateTrackBlock Aug 31 15:57:51 bcik volumio[28216]: info: CorePlayQueue::getTrackBlock Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: Reloading queue from file Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::setRepeat false single undefined Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::pushState Aug 31 15:57:51 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::setRandom false Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::pushState Aug 31 15:57:51 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:51 bcik volumio[28216]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 15:57:51 bcik volumio[28216]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 15:57:51 bcik volumio[28216]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: Setting Device type: Raspberry PI Aug 31 15:57:51 bcik volumio[28216]: info: Completed loading Core Plugins Aug 31 15:57:51 bcik volumio[28216]: info: Preparing to generate the ALSA configuration file Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:57:51 bcik volumio[28216]: info: CoreStateMachine::pushState Aug 31 15:57:51 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioPushState Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: Asound.conf file unchanged, so no further update is needed Aug 31 15:57:51 bcik volumio[28216]: info: Output device has changed, restarting MPD Aug 31 15:57:51 bcik volumio[28216]: info: Output device has changed, restarting Shairport Sync Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:51 bcik sudo[28328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:57:51 bcik sudo[28328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik volumio[28216]: info: ___________ START PLUGINS ___________ Aug 31 15:57:51 bcik sudo[28328]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:51 bcik sudo[28330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:57:51 bcik sudo[28330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik volumio[28216]: info: ControllerMpd::onStart: Initializing MPD Aug 31 15:57:51 bcik volumio[28216]: info: Creating MPD Configuration file Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:51 bcik volumio[28216]: info: [1788184671498] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:51 bcik sudo[28338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 15:57:51 bcik sudo[28338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 15:57:51 bcik volumio[28216]: info: UPNP Browser: Client initialized successfully Aug 31 15:57:51 bcik sudo[28340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:57:51 bcik sudo[28340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik sudo[28340]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:51 bcik sudo[28342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:57:51 bcik sudo[28342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:57:51 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:57:51 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:57:51 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:57:51 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:57:51 bcik volumio[28216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:51 bcik volumio[28216]: info: [1788184671550] CoreMusicLibrary::Adding element Last_100 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:51 bcik volumio[28216]: info: [1788184671551] CoreMusicLibrary::Adding element Webradio Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:51 bcik volumio[28216]: info: Initializing BBC Radios Aug 31 15:57:51 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:57:51 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:57:51 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:57:51 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:57:51 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:57:51 bcik sudo[28338]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:51 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:57:51 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:57:51 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:57:51 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:57:51 bcik volumio[28284]: Starting albumart workers Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: Creating Spotify config file Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik sudo[28367]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 15:57:51 bcik sudo[28367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 15:57:51 bcik sudo[28367]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:51 bcik volumio[28285]: Starting albumart workers Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:57:51 bcik volumio[28216]: info: [1788184671774] CoreMusicLibrary::Adding element Radio Browser Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:57:51 bcik volumio[28216]: Cannot find translation for source Radio Browser Aug 31 15:57:51 bcik volumio[28216]: info: Volumio Calling Home Aug 31 15:57:51 bcik volumio[28283]: Starting albumart workers Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: MPD Permissions set Aug 31 15:57:51 bcik volumio[28216]: info: MPD Permissions set Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: Spotify config file written Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik sudo[28384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik sudo[28384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:51 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:51 bcik go-librespot[28398]: go-librespot daemon starting... Aug 31 15:57:51 bcik go-librespot[28402]: time="2026-08-31T15:57:51+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:51 bcik go-librespot[28402]: time="2026-08-31T15:57:51+02:00" level=debug msg="app state loaded" Aug 31 15:57:51 bcik sudo[28384]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:51 bcik go-librespot[28402]: time="2026-08-31T15:57:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:57:51 bcik volumio[28216]: info: No need to fix Spotify hosts Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:51 bcik volumio[28216]: info: Volumio called home Aug 31 15:57:51 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:51 bcik volumio[28216]: info: Starting Shairport Sync Aug 31 15:57:51 bcik volumio[28216]: info: Starting Shairport Sync Aug 31 15:57:51 bcik volumio[28216]: info: Starting Shairport Sync Aug 31 15:57:51 bcik sudo[28412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:51 bcik sudo[28412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik sudo[28416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:51 bcik sudo[28416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:51 bcik volumio[28216]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:57:51 bcik volumio[28216]: info: Discovery: Found device Bącik Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:51 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:51 bcik volumio[28216]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:57:51 bcik volumio[28216]: info: Discovery: Found device Bącik Aug 31 15:57:51 bcik volumio[28216]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:51 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:51 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:57:51 bcik sudo[28414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:57:51 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:57:51 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:51 bcik systemd[1]: shairport-sync.service: Consumed 1.532s CPU time. Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:51+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:51+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:51+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:52 bcik sudo[28414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:52+02:00" level=info msg="zeroconf server listening on port 33065" Aug 31 15:57:52 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:52 bcik volumio[28216]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik sudo[28412]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:52 bcik volumio[28216]: info: CoreCommandRouter::volumioGetState Aug 31 15:57:52 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:57:52 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:57:52 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:52 bcik volumio[28216]: info: Shairport-Sync Started Aug 31 15:57:52 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:57:52 bcik volumio[28216]: Error adding Membership: Error: addMembership EINVAL Aug 31 15:57:52 bcik sudo[28414]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik sudo[28416]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:52 bcik volumio[28216]: info: Shairport-Sync Started Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: info: Shairport-Sync Started Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:52+02:00" level=debug msg="obtained new client token: AAFDJ3JIkCd7d5h2ZdvULeGDUhKKz0Vz93cpslEoxQ9nqC6h2X8vB5E8C0DRcvwUnMzV/bY8RGCgrs8HXpg2EAgDZcR4T5EmKjNMM2EtJcT1SHGRYnO2G6jrabEXvyk8tiyw7COIVm/or5drSdi7htAX4vhIQGzWEn1s57/8injnS1PHH0XQaVZijEN3S0Sqjz8dmS6e8BNYd+zUTsp+q6HZdQZ0iIZOfr2tgsFChMG3l9sOUz/Z" Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:52+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:52+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:52+02:00" level=debug msg="completed challenge" Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:52+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:52 bcik mpd[28372]: 2026-08-31T15:57:52 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 15:57:52 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 15:57:52 bcik sudo[28342]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:52 bcik sudo[28330]: pam_unix(sudo:session): session closed for user root Aug 31 15:57:52 bcik volumio[28216]: info: Completed starting Core Plugins Aug 31 15:57:52 bcik volumio[28216]: info: ------------------------------------------- Aug 31 15:57:52 bcik volumio[28216]: info: ----- MyVolumio plugins startup ---- Aug 31 15:57:52 bcik volumio[28216]: info: ------------------------------------------- Aug 31 15:57:52 bcik volumio[28216]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 15:57:52 bcik volumio[28216]: info: MPD running with PID28372 Aug 31 15:57:52 bcik volumio[28216]: ,establishing connection Aug 31 15:57:52 bcik volumio[28216]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:57:52 bcik volumio[28216]: assert.ok(self.idling) Aug 31 15:57:52 bcik volumio[28216]: error: The expression evaluated to a falsy value: Aug 31 15:57:52 bcik volumio[28216]: assert.ok(self.idling) Aug 31 15:57:52 bcik volumio[28216]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:57:52 bcik volumio[28216]: assert.ok(self.idling) Aug 31 15:57:52 bcik volumio[28216]: error: The expression evaluated to a falsy value: Aug 31 15:57:52 bcik volumio[28216]: assert.ok(self.idling) Aug 31 15:57:52 bcik volumio[28216]: error: updateQueue error: null Aug 31 15:57:52 bcik go-librespot[28402]: time="2026-08-31T15:57:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:52 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:52 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:54 bcik volumio-remote-updater[962]: [2026-08-31 15:57:54] [connect] Successful connection Aug 31 15:57:54 bcik volumio-remote-updater[962]: [2026-08-31 15:57:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788184674 101 Aug 31 15:57:54 bcik volumio[28216]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Aug 31 15:57:54 bcik volumio[28216]: info: go-librespot daemon successfully initialized Aug 31 15:57:55 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Aug 31 15:57:55 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:55 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:55 bcik go-librespot[28449]: go-librespot daemon starting... Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="app state loaded" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=info msg="zeroconf server listening on port 46337" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="obtained new client token: AAGdLChpajAAyfiA6YnmH+3iPNZiDtQYFJgbNj24b//BjR+Bi73k7C5n282RAFbKFYgFpFerRa+ujSEdgSlF59rYsyOC696tykyKwcRHBFvTtILm4dLtltatwgFPT12BNrXacQ3G+U3BcNNuTIOOTylvKAcSwV2Y9Zwmdlke87Q2Nn5+vSbFDvR3vr6ZRvJwT+CSvQ7ZBKSSBcrzSV4Z+t8qXrL8vIOMC8S/q2O/v0sAWJlaSgw43ZE=" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=debug msg="completed challenge" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:55 bcik go-librespot[28450]: time="2026-08-31T15:57:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:55 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:55 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:57:57 bcik volumio[28216]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:57:57 bcik volumio[28216]: info: Initializing connection to go-librespot Websocket Aug 31 15:57:57 bcik volumio[28216]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:57:58 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Aug 31 15:57:58 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:58 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:57:58 bcik go-librespot[28459]: go-librespot daemon starting... Aug 31 15:57:58 bcik go-librespot[28460]: time="2026-08-31T15:57:58+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:57:58 bcik go-librespot[28460]: time="2026-08-31T15:57:58+02:00" level=debug msg="app state loaded" Aug 31 15:57:58 bcik go-librespot[28460]: time="2026-08-31T15:57:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57: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-gae2.spotify.com:80]" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=info msg="zeroconf server listening on port 35793" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=debug msg="obtained new client token: AAEOjoYNR6Zrjk4C2xilX5hHNe2u5o82MWYepF0MElFmp0w9MRqGCjpLFx/0srkfHUAK8UTlCJAKIHTv0Zoahg6mIaTs7hQIb5pzJzhajF62U3e/rF1qBsFWouL4K5qFrp0veKHXMCHRTeRZko41EuUETuNBg+WpcMDhQJmidvYE7Xb1cJ6mVMsYFS3Nd0ssEvkv0fucXAPsLri2Nlb2lu06YsI6uhZaugUR0O3qf7tvNkJQmpHv" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=debug msg="completed keyexchange" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=debug msg="completed challenge" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:57:59 bcik go-librespot[28460]: time="2026-08-31T15:57:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:57:59 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:57:59 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:58:00 bcik volumio[28216]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:58:00 bcik volumio[28216]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:58:00 bcik volumio[28216]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:58:00 bcik volumio[28216]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:58:00 bcik volumio[28216]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:58:00 bcik volumio[28216]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:58:00 bcik volumio[28216]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:58:00 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:00 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:00 bcik volumio[28216]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:58:00 bcik volumio[28216]: info: MyVolumio login type: Token Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:58:00 bcik volumio[28216]: info: Streaming services startup Aug 31 15:58:00 bcik volumio[28216]: info: Starting Streaming Daemon Aug 31 15:58:00 bcik sudo[28484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:58:00 bcik sudo[28484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:00 bcik volumio[28216]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:58:00 bcik sudo[28484]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:00 bcik sudo[28491]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:58:00 bcik volumio[28216]: error: Cannot start Volumio Streaming Daemon Aug 31 15:58:00 bcik volumio[28216]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:58:00 bcik volumio[28216]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:58:00 bcik sudo[28491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:00 bcik sudo[28491]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:00 bcik sudo[28493]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:58:00 bcik sudo[28493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:00 bcik sudo[28493]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:00 bcik volumio[28216]: info: Initializing connection to go-librespot Websocket Aug 31 15:58:00 bcik volumio[28216]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:58:00 bcik sudo[28497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:58:00 bcik sudo[28497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:00 bcik sudo[28497]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:00 bcik volumio[28216]: info: Upmpdcli Daemon Started Aug 31 15:58:01 bcik volumio[28216]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:58:01 bcik volumio[28216]: info: MyVolumio token set successfully Aug 31 15:58:01 bcik volumio[28216]: info: MYVOLUMIO: Adding device Aug 31 15:58:01 bcik volumio[28216]: info: MYVOLUMIO: Evaluating Server Aug 31 15:58:01 bcik volumio[28216]: info: MyVolumio status changed Aug 31 15:58:01 bcik volumio[28216]: info: Streaming services startup Aug 31 15:58:01 bcik volumio[28216]: info: Starting Streaming Daemon Aug 31 15:58:01 bcik volumio[28216]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:58:01 bcik volumio[28216]: info: Removing audio output: Aug 31 15:58:01 bcik volumio[28216]: info: Stoppping Tunnel 1 Aug 31 15:58:01 bcik sudo[28520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:58:01 bcik sudo[28520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:01 bcik sudo[28522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:58:01 bcik sudo[28522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik sudo[28520]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:01 bcik volumio[28216]: error: Cannot start Volumio Streaming Daemon Aug 31 15:58:01 bcik volumio[28216]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:58:01 bcik volumio[28216]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:01 bcik sudo[28522]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:01 bcik volumio[28216]: info: Remote SSH Stopped Aug 31 15:58:02 bcik volumio[28216]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:58:02 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:02 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:02 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:02 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Aug 31 15:58:02 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:02 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:02 bcik go-librespot[28525]: go-librespot daemon starting... Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=debug msg="app state loaded" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=info msg="zeroconf server listening on port 44849" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=debug msg="obtained new client token: AAEbqNk0SQTYg9KeAl7F2EJbvxSyWE4RyXH6Cf9/IPXqfmj9up/+BA2U+gPHLq/xOHaJP2/Ym0CRxtMq+5jiqu88+uZTKJz6bULwwcmkW9Md2eLzjrS3ql6UADIxK7h9ilObuv3v97CK3wB+VT9BuEcHEFuaXU0F11IUYxww0z3VBFrqdOgToJs7LhKo+sSdqQfOdvri1OmYef/+uCB2yiY5SFFF6HUj4+lt4T6nlkiROWbPmJcaIpc=" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=debug msg="completed keyexchange" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=debug msg="completed challenge" Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:58:02 bcik volumio[28216]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:58:02 bcik go-librespot[28526]: time="2026-08-31T15:58:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:58:02 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:02 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:03 bcik volumio[28216]: info: Updating MyVolumio device info Aug 31 15:58:03 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:03 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:03 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:03 bcik volumio[28216]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:58:03 bcik volumio[28216]: info: Initializing connection to go-librespot Websocket Aug 31 15:58:03 bcik volumio[28216]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:58:06 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Aug 31 15:58:06 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:06 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:06 bcik go-librespot[28536]: go-librespot daemon starting... Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="app state loaded" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=info msg="zeroconf server listening on port 46173" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="obtained new client token: AAGxlgipItWTlW7bIm8ONXfHklsLfcUSdR+9UHke7AIzH94QYZboiYP4PQYDS5Ep51pWvfxXiL9TjzCPfTPVJZu23LMinNV2UcQsHggk9lVtzwanEp7+hG7AvXPB9o6qQP1G8Gyy50PWhADLAHzPmD7VX/9tT1HknlIG3ce9YnphOZ/6XjaJp7TnEzXAMQ4YB46tRaS6Pta1/wXoDt1pfgNHzjQcA4GMG/h1Z8CidRmTKrAqymoY" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="completed keyexchange" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=debug msg="completed challenge" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:58:06 bcik go-librespot[28537]: time="2026-08-31T15:58:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:58:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:06 bcik volumio[28216]: info: MYVOLUMIO: Adding device Aug 31 15:58:06 bcik volumio[28216]: info: MYVOLUMIO: Evaluating Server Aug 31 15:58:06 bcik volumio[28216]: info: Initializing connection to go-librespot Websocket Aug 31 15:58:06 bcik volumio[28216]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:58:07 bcik volumio[28216]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:58:07 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:07 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:07 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:07 bcik volumio[28216]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:58:08 bcik volumio[28216]: info: Updating MyVolumio device info Aug 31 15:58:08 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:08 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:08 bcik volumio[28216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:08 bcik volumio[28216]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:58:09 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Aug 31 15:58:09 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:09 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:09 bcik go-librespot[28564]: go-librespot daemon starting... Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=debug msg="app state loaded" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=info msg="zeroconf server listening on port 34835" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=debug msg="obtained new client token: AAHhqoDsy4r4aXxKhQneuRNOy8v+os+UmdFSfDXXLoggJDOvVwAQ5GjBjM5iw6ra4vu2M0uYtjp2tfDpImVoCwDfMtT8Y5rYE3K0W7N48XOia6KMud8Xs8SGjLxYWGlt8noHWjZQvxkQGRe1ROSI6cnCMQoPuaW0McV20m4kJnHt6iHf53Jmv6mbNR5OcPTNXKIe34c8llshDJwRG6mwuoppTidXezYF5GViB5VHTBawWf12N3cSGuM=" Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:58:09 bcik volumio[28216]: info: Initializing connection to go-librespot Websocket Aug 31 15:58:09 bcik go-librespot[28565]: time="2026-08-31T15:58:09+02:00" level=debug msg="new websocket client" Aug 31 15:58:09 bcik volumio[28216]: info: Connection to go-librespot Websocket established Aug 31 15:58:12 bcik volumio[28216]: info: Getting Spotify volume Aug 31 15:58:12 bcik volumio[28216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 15:58:12 bcik volumio[28216]: info: CoreCommandRouter::volumioGetState Aug 31 15:58:12 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:12 bcik volumio[28216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Aug 31 15:58:12 bcik volumio[28216]: SPOTIFY: SPOTIFY VOLUME undefined Aug 31 15:58:12 bcik volumio[28216]: SPOTIFY: VOLUMIO VOLUME 53 Aug 31 15:58:12 bcik volumio[28216]: info: Aligning Spotify Volume to Volumio Volume Aug 31 15:58:12 bcik volumio[28216]: info: CoreCommandRouter::volumioGetState Aug 31 15:58:12 bcik volumio[28216]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:12 bcik volumio[28216]: info: Setting Spotify Volume from Volumio: 53 Aug 31 15:58:14 bcik go-librespot[28565]: time="2026-08-31T15:58:14+02:00" level=debug msg="completed keyexchange" Aug 31 15:58:14 bcik go-librespot[28565]: time="2026-08-31T15:58:14+02:00" level=debug msg="completed challenge" Aug 31 15:58:14 bcik go-librespot[28565]: time="2026-08-31T15:58:14+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:58:14 bcik go-librespot[28565]: time="2026-08-31T15:58:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:58:14 bcik volumio[28216]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:58:14 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:14 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:14 bcik volumio[28216]: Error: socket hang up Aug 31 15:58:14 bcik volumio[28216]: at connResetException (node:internal/errors:720:14) Aug 31 15:58:14 bcik volumio[28216]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 31 15:58:14 bcik volumio[28216]: at Socket.emit (node:events:526:35) Aug 31 15:58:14 bcik volumio[28216]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 31 15:58:14 bcik volumio[28216]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 31 15:58:14 bcik volumio[28216]: code: 'ECONNRESET', Aug 31 15:58:14 bcik volumio[28216]: response: undefined Aug 31 15:58:14 bcik volumio[28216]: } Aug 31 15:58:14 bcik volumio[28216]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:58:14 bcik sudo[28602]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:57' Aug 31 15:58:14 bcik sudo[28602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:14 bcik sudo[28602]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:14 bcik volumio-remote-updater[962]: [2026-08-31 15:58:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 15:58:14 bcik volumio-remote-updater[962]: [2026-08-31 15:58:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 15:58:14 bcik volumio5-onboarding[1666]: time=2026-08-31T15:58:14.699+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 15:58:14 bcik volumio5-onboarding[1666]: time=2026-08-31T15:58:14.700+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 15:58:14 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:14 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 15:58:14 bcik systemd[1]: volumio.service: Consumed 6.463s CPU time. Aug 31 15:58:14 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:58:14 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:58:15 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 244. Aug 31 15:58:15 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:58:15 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 15:58:15 bcik systemd[1]: volumio.service: Consumed 6.463s CPU time. Aug 31 15:58:15 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 15:58:15 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:58:15 bcik volumio[28614]: info: ------------------------------------------- Aug 31 15:58:15 bcik volumio[28614]: info: ----- Volumio3 ---- Aug 31 15:58:15 bcik volumio[28614]: info: ------------------------------------------- Aug 31 15:58:15 bcik volumio[28614]: info: ----- System startup ---- Aug 31 15:58:15 bcik volumio[28614]: info: ------------------------------------------- Aug 31 15:58:15 bcik volumio[28614]: info: MYVOLUMIO Environment detected Aug 31 15:58:15 bcik volumio[28614]: info: Plugin folders cleanup Aug 31 15:58:15 bcik volumio[28614]: info: Scanning into folder /volumio/app/plugins/ Aug 31 15:58:15 bcik volumio[28614]: info: Scanning category audio_interface Aug 31 15:58:15 bcik volumio[28614]: info: Scanning category miscellanea Aug 31 15:58:15 bcik volumio[28614]: info: Scanning category music_service Aug 31 15:58:15 bcik volumio[28614]: info: Scanning category plugins.json Aug 31 15:58:15 bcik volumio[28614]: info: Scanning category system_controller Aug 31 15:58:15 bcik volumio[28614]: info: Scanning category user_interface Aug 31 15:58:15 bcik volumio[28614]: info: Scanning into folder /data/plugins/ Aug 31 15:58:15 bcik volumio[28614]: info: Scanning category music_service Aug 31 15:58:15 bcik volumio[28614]: info: Plugin folders cleanup completed Aug 31 15:58:15 bcik volumio[28614]: info: ------------------------------------------- Aug 31 15:58:15 bcik volumio[28614]: info: ----- Core plugins startup ---- Aug 31 15:58:15 bcik volumio[28614]: info: ------------------------------------------- Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 15:58:15 bcik volumio[28614]: info: Adding plugin upnp to MyMusic Plugins Aug 31 15:58:15 bcik volumio[28614]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 15:58:15 bcik volumio[28614]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugins from folder /data/plugins/ Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "system"... Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "appearance"... Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "network"... Aug 31 15:58:15 bcik volumio[28614]: info: Refreshing Cached IP Addresses Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "services"... Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "volumio5onboarding"... Aug 31 15:58:15 bcik sudo[28642]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:58:15 bcik sudo[28644]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:58:15 bcik sudo[28642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:15 bcik sudo[28644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:15 bcik sudo[28642]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:15 bcik sudo[28644]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "alsa_controller"... Aug 31 15:58:15 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "wizard"... Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "networkfs"... Aug 31 15:58:15 bcik volumio[28614]: info: Starting Udev Watcher for removable devices Aug 31 15:58:15 bcik volumio[28614]: info: Ignoring mount for partition: boot Aug 31 15:58:15 bcik volumio[28614]: info: Ignoring mount for partition: volumio Aug 31 15:58:15 bcik volumio[28614]: info: Ignoring mount for partition: volumio_data Aug 31 15:58:15 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "volumio_command_line_client"... Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "upnp"... Aug 31 15:58:15 bcik volumio[28614]: info: [1788184695827] Starting Upmpd Daemon Aug 31 15:58:15 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "my_music"... Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "mpd"... Aug 31 15:58:15 bcik volumio[28614]: info: Loading plugin "upnp_browser"... Aug 31 15:58:16 bcik volumio[28614]: info: Starting UPNP Browser Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "alarm-clock"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "airplay_emulation"... Aug 31 15:58:16 bcik volumio[28614]: info: Starting Shairport Sync Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "last_100"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "webradio"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "i2s_dacs"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "volumiodiscovery"... Aug 31 15:58:16 bcik volumio[28614]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:58:16 bcik node[28614]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:58:16 bcik volumio[28614]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:58:16 bcik node[28614]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:58:16 bcik volumio[28614]: *** WARNING *** For more information see Aug 31 15:58:16 bcik node[28614]: *** WARNING *** For more information see Aug 31 15:58:16 bcik volumio[28614]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:58:16 bcik node[28614]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:58:16 bcik volumio[28614]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:58:16 bcik node[28614]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:58:16 bcik volumio[28614]: *** WARNING *** For more information see Aug 31 15:58:16 bcik node[28614]: *** WARNING *** For more information see Aug 31 15:58:16 bcik volumio[28614]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 15:58:16 bcik volumio[28614]: info: Discovery: Started advertising with name: Bącik Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "spop"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "outputs"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "albumart"... Aug 31 15:58:16 bcik volumio[28614]: info: Plugin example_plugin is not enabled Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "inputs"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "updater_comm"... Aug 31 15:58:16 bcik volumio[28614]: info: Plugin mpdemulation is not enabled Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "rest_api"... Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "websocket"... Aug 31 15:58:16 bcik volumio[28614]: info: Starting Socket.io Server version 1.7.4 Aug 31 15:58:16 bcik volumio[28614]: info: Loading plugin "radio_browser"... Aug 31 15:58:16 bcik volumio[28674]: Forking 3 albumart workers Aug 31 15:58:16 bcik volumio[28614]: info: Loading i18n strings for locale pl Aug 31 15:58:16 bcik volumio[28614]: Updating browse sources language Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::initPlayerControls Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: Express server listening on port 3000 Aug 31 15:58:16 bcik volumio[28614]: [Metrics] WebUI: 1s 297.52ms Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::resetVolumioState Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::getcurrentVolume Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:58:16 bcik volumio[28614]: info: Volumio Network Manager: Network status updated: 1 Aug 31 15:58:16 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:58:16 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: Reloading queue from file Aug 31 15:58:16 bcik volumio[28614]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::pushState Aug 31 15:58:16 bcik volumio[28614]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioPushState Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::updateTrackBlock Aug 31 15:58:16 bcik volumio[28614]: info: CorePlayQueue::getTrackBlock Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::setRepeat false single undefined Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::pushState Aug 31 15:58:16 bcik volumio[28614]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioPushState Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::setRandom false Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::pushState Aug 31 15:58:16 bcik volumio[28614]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioPushState Aug 31 15:58:16 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:58:16 bcik volumio[28614]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 15:58:16 bcik volumio[28614]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 15:58:16 bcik volumio[28614]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 15:58:16 bcik volumio[28614]: info: Setting Device type: Raspberry PI Aug 31 15:58:16 bcik volumio[28614]: info: Completed loading Core Plugins Aug 31 15:58:16 bcik volumio[28614]: info: Preparing to generate the ALSA configuration file Aug 31 15:58:16 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:58:16 bcik volumio[28614]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:58:16 bcik volumio[28614]: info: CoreStateMachine::pushState Aug 31 15:58:16 bcik volumio[28614]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioPushState Aug 31 15:58:16 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:58:16 bcik volumio[28614]: info: Asound.conf file unchanged, so no further update is needed Aug 31 15:58:16 bcik volumio[28614]: info: Output device has changed, restarting MPD Aug 31 15:58:16 bcik sudo[28728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:58:16 bcik volumio[28614]: info: Output device has changed, restarting Shairport Sync Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:16 bcik sudo[28728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:16 bcik sudo[28728]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:16 bcik volumio[28614]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:58:16 bcik volumio[28614]: info: ___________ START PLUGINS ___________ Aug 31 15:58:16 bcik sudo[28730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:58:16 bcik sudo[28730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:16 bcik volumio[28614]: info: ControllerMpd::onStart: Initializing MPD Aug 31 15:58:16 bcik volumio[28614]: info: Creating MPD Configuration file Aug 31 15:58:16 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 15:58:16 bcik sudo[28738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 15:58:16 bcik sudo[28738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:58:16 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:58:16 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:58:16 bcik volumio[28614]: info: [1788184696793] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 15:58:16 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:58:16 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:58:16 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:58:16 bcik volumio[28614]: info: UPNP Browser: Client initialized successfully Aug 31 15:58:16 bcik sudo[28740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:58:16 bcik sudo[28740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:16 bcik sudo[28743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:58:16 bcik sudo[28743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:16 bcik sudo[28740]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:16 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:58:16 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:58:16 bcik volumio[28614]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:16 bcik sudo[28738]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:16 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:58:16 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:58:16 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:58:16 bcik volumio[28684]: Starting albumart workers Aug 31 15:58:16 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:58:16 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:58:16 bcik volumio[28614]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:58:16 bcik volumio[28614]: info: [1788184696848] CoreMusicLibrary::Adding element Last_100 Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:58:16 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:58:16 bcik volumio[28614]: info: [1788184696849] CoreMusicLibrary::Adding element Webradio Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:58:16 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:58:16 bcik volumio[28614]: info: Initializing BBC Radios Aug 31 15:58:16 bcik sudo[28757]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 15:58:16 bcik volumio[28686]: Starting albumart workers Aug 31 15:58:16 bcik sudo[28757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 15:58:16 bcik sudo[28757]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:16 bcik volumio[28614]: info: Creating Spotify config file Aug 31 15:58:16 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:16 bcik volumio[28685]: Starting albumart workers Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:58:17 bcik volumio[28614]: info: [1788184697073] CoreMusicLibrary::Adding element Radio Browser Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:58:17 bcik volumio[28614]: Cannot find translation for source Radio Browser Aug 31 15:58:17 bcik volumio[28614]: info: Volumio Calling Home Aug 31 15:58:17 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 15:58:17 bcik volumio[28614]: info: MPD Permissions set Aug 31 15:58:17 bcik volumio[28614]: info: MPD Permissions set Aug 31 15:58:17 bcik volumio[28614]: error: Upnp client error: Error: This socket has been ended by the other party Aug 31 15:58:17 bcik volumio[28614]: info: Spotify config file written Aug 31 15:58:17 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik sudo[28789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 15:58:17 bcik sudo[28789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:58:17 bcik volumio[28614]: info: No need to fix Spotify hosts Aug 31 15:58:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:17 bcik go-librespot[28797]: go-librespot daemon starting... Aug 31 15:58:17 bcik sudo[28789]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:17 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=debug msg="app state loaded" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:58:17 bcik volumio[28614]: info: Volumio called home Aug 31 15:58:17 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:58:17 bcik volumio[28614]: info: Starting Shairport Sync Aug 31 15:58:17 bcik volumio[28614]: info: Starting Shairport Sync Aug 31 15:58:17 bcik volumio[28614]: info: Starting Shairport Sync Aug 31 15:58:17 bcik sudo[28815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:58:17 bcik sudo[28815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:17 bcik sudo[28818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:58:17 bcik sudo[28818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:17 bcik sudo[28820]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:58:17 bcik sudo[28820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:17 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:58:17 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:58:17 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:58:17 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:58:17 bcik systemd[1]: shairport-sync.service: Consumed 1.541s CPU time. Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58: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]" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58: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]" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58: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]" Aug 31 15:58:17 bcik volumio[28614]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=info msg="zeroconf server listening on port 38221" Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::volumioGetState Aug 31 15:58:17 bcik volumio[28614]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:17 bcik volumio[28614]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 15:58:17 bcik volumio[28614]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:58:17 bcik volumio[28614]: info: Discovery: Found device Bącik Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::volumioGetState Aug 31 15:58:17 bcik volumio[28614]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:17 bcik volumio[28614]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:58:17 bcik volumio[28614]: info: Discovery: Found device Bącik Aug 31 15:58:17 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:58:17 bcik sudo[28815]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:17 bcik volumio[28614]: info: CoreCommandRouter::volumioGetState Aug 31 15:58:17 bcik sudo[28818]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:17 bcik volumio[28614]: info: CorePlayQueue::getTrack 0 Aug 31 15:58:17 bcik sudo[28820]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:17 bcik volumio[28614]: info: Shairport-Sync Started Aug 31 15:58:17 bcik volumio[28614]: Error adding Membership: Error: addMembership EINVAL Aug 31 15:58:17 bcik volumio[28614]: info: Shairport-Sync Started Aug 31 15:58:17 bcik volumio[28614]: info: Shairport-Sync Started Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=debug msg="obtained new client token: AAFm/uWYBI+PzW3+SLNZU/LMoMLWAbdLmmC9hnIc4g/deE+VArb4x/cflSxXGBMSuAA7JrAixdRqBJVMRcNTi2SxbfcnUsWcpHJwXrwFdbjhI2dreECQ9y/n7yxGhY32wsVD8rpvyYzgaq41R/zL2Sh4KFFTqCFiqsPcbIO8OLSWlI7IiCtivdqAqU0u94KH/4gKS38DSSGxG9CDTnXzzRwRuihW+BQcGt5A81oD5/DS+BQH4W64rf8=" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=debug msg="completed keyexchange" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=debug msg="completed challenge" Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:58:17 bcik mpd[28769]: 2026-08-31T15:58:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 15:58:17 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 15:58:17 bcik sudo[28743]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:17 bcik sudo[28730]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:17 bcik volumio[28614]: info: Completed starting Core Plugins Aug 31 15:58:17 bcik volumio[28614]: info: ------------------------------------------- Aug 31 15:58:17 bcik volumio[28614]: info: ----- MyVolumio plugins startup ---- Aug 31 15:58:17 bcik volumio[28614]: info: ------------------------------------------- Aug 31 15:58:17 bcik volumio[28614]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 15:58:17 bcik volumio[28614]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:58:17 bcik volumio[28614]: assert.ok(self.idling) Aug 31 15:58:17 bcik volumio[28614]: error: The expression evaluated to a falsy value: Aug 31 15:58:17 bcik volumio[28614]: assert.ok(self.idling) Aug 31 15:58:17 bcik volumio[28614]: error: updateQueue error: null Aug 31 15:58:17 bcik volumio[28614]: info: MPD running with PID28769 Aug 31 15:58:17 bcik volumio[28614]: ,establishing connection Aug 31 15:58:17 bcik volumio[28614]: error: updateQueue error: null Aug 31 15:58:17 bcik go-librespot[28808]: time="2026-08-31T15:58:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:58:17 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:17 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:19 bcik volumio-remote-updater[962]: [2026-08-31 15:58:19] [connect] Successful connection Aug 31 15:58:19 bcik volumio-remote-updater[962]: [2026-08-31 15:58:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788184699 101 Aug 31 15:58:19 bcik volumio[28614]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Aug 31 15:58:20 bcik volumio[28614]: info: go-librespot daemon successfully initialized Aug 31 15:58:20 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Aug 31 15:58:20 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:20 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:20 bcik go-librespot[28847]: go-librespot daemon starting... Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=debug msg="app state loaded" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58: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-gew1.spotify.com:80]" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=info msg="zeroconf server listening on port 37645" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=debug msg="obtained new client token: AAEk8jWXOzAu2DStgOeUCvURNZnVZ4TFX3f1P+O6whI/oKM5/i2QAuU33cOQhffMtPfL49WpMhiezoxda5Vx3cyO1N6viw7xM35YCWSEMBNuGFQziZHwzaavpjS8ZISTgg3UVHFBuM9LVrWHGwQXbXcdlS9E6TqMKlzWR22z+0IQ55TLtCiw/IaYQAsEVvwQRobDiGlQCefeLXMEQUd1z9xi6eEz81jHvQ4bZgErqvxtsJMfKXckJ7M=" Aug 31 15:58:20 bcik go-librespot[28848]: time="2026-08-31T15:58:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:58:21 bcik go-librespot[28848]: time="2026-08-31T15:58:21+02:00" level=debug msg="completed keyexchange" Aug 31 15:58:21 bcik go-librespot[28848]: time="2026-08-31T15:58:21+02:00" level=debug msg="completed challenge" Aug 31 15:58:21 bcik go-librespot[28848]: time="2026-08-31T15:58:21+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:58:21 bcik go-librespot[28848]: time="2026-08-31T15:58:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:58:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:22 bcik volumio[28614]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:58:23 bcik volumio[28614]: info: Initializing connection to go-librespot Websocket Aug 31 15:58:23 bcik volumio[28614]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:58:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Aug 31 15:58:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:24 bcik go-librespot[28857]: go-librespot daemon starting... Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=debug msg="app state loaded" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=info msg="zeroconf server listening on port 45431" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=debug msg="obtained new client token: AAHD7ZmXxc3Lt0El43DmLIUJYDjoFwU8DNuqDnAJ+mAcpuJV97ozGoPolnz0iu5hs666rVrag9UJVStOW/pMjGgCVa8Rbp3jd2v0Cri5BNEZn66xG0TT3UZze0oG08t0ZU5eyKeCv5VGYW+6SgtIUUSXpV8OiIr3q2x3XhR6goAvlQqEmSUwOzADoj7i/FDIpQgdD3kngRcSxOl1ateQAKVg/+/ueHZVEBKRut/p1RYH2XuH+RCdsoE=" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=debug msg="completed keyexchange" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=debug msg="completed challenge" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:58:24 bcik go-librespot[28858]: time="2026-08-31T15:58:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:58:24 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:24 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:58:25 bcik volumio[28614]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:58:25 bcik volumio[28614]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:58:25 bcik volumio[28614]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:58:25 bcik volumio[28614]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:58:25 bcik volumio[28614]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:58:25 bcik volumio[28614]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:58:25 bcik volumio[28614]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:58:25 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:25 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:25 bcik volumio[28614]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:58:25 bcik volumio[28614]: info: MyVolumio login type: Token Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:58:25 bcik volumio[28614]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:58:26 bcik volumio[28614]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:58:26 bcik volumio[28614]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:58:26 bcik volumio[28614]: info: Streaming services startup Aug 31 15:58:26 bcik volumio[28614]: info: Starting Streaming Daemon Aug 31 15:58:26 bcik sudo[28883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:58:26 bcik sudo[28883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:26 bcik volumio[28614]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:58:26 bcik sudo[28883]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:26 bcik sudo[28890]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:58:26 bcik sudo[28890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:26 bcik volumio[28614]: error: Cannot start Volumio Streaming Daemon Aug 31 15:58:26 bcik volumio[28614]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:58:26 bcik volumio[28614]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:58:26 bcik sudo[28890]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:26 bcik sudo[28892]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:58:26 bcik sudo[28892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:26 bcik sudo[28892]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:26 bcik sudo[28896]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:58:26 bcik sudo[28896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:26 bcik sudo[28896]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:26 bcik volumio[28614]: info: Upmpdcli Daemon Started Aug 31 15:58:26 bcik volumio[28614]: info: Initializing connection to go-librespot Websocket Aug 31 15:58:26 bcik volumio[28614]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:58:26 bcik volumio[28614]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:58:26 bcik volumio[28614]: info: MyVolumio token set successfully Aug 31 15:58:26 bcik volumio[28614]: info: MYVOLUMIO: Adding device Aug 31 15:58:26 bcik volumio[28614]: info: MYVOLUMIO: Evaluating Server Aug 31 15:58:26 bcik volumio[28614]: info: MyVolumio status changed Aug 31 15:58:26 bcik volumio[28614]: info: Streaming services startup Aug 31 15:58:26 bcik volumio[28614]: info: Starting Streaming Daemon Aug 31 15:58:26 bcik volumio[28614]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:58:26 bcik volumio[28614]: info: Removing audio output: Aug 31 15:58:26 bcik volumio[28614]: info: Stoppping Tunnel 1 Aug 31 15:58:26 bcik sudo[28920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:58:26 bcik sudo[28920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:26 bcik sudo[28922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:58:26 bcik sudo[28922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:58:26 bcik sudo[28920]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:26 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:26 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:26 bcik volumio[28614]: error: Cannot start Volumio Streaming Daemon Aug 31 15:58:26 bcik volumio[28614]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:58:26 bcik volumio[28614]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:58:26 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:26 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:26 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:26 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 15:58:26 bcik sudo[28922]: pam_unix(sudo:session): session closed for user root Aug 31 15:58:26 bcik volumio[28614]: info: Remote SSH Stopped Aug 31 15:58:27 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Aug 31 15:58:27 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:27 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:58:27 bcik go-librespot[28925]: go-librespot daemon starting... Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=debug msg="app state loaded" Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=info msg="zeroconf server listening on port 44911" Aug 31 15:58:27 bcik go-librespot[28926]: time="2026-08-31T15:58:27+02:00" level=debug msg="obtained new client token: AAHIvpwe+ZdkpNiP3v9efXOo+B1qPKMzFupyLot+AF1E3/UHmh82VD7xUMV2BAP6kMHoSzBGgYwwGYr+FgJ0AKEDqfMU6tduSv6iMD4gCvfZvBKw/U6UtVFM/xMa4nJ61FY+CcTjNQW8heQnbqsnfItfhNwrsgyoQqBWdSCzAGKN8T/ZFLgfRbfwfQYkqfony8xLf4VulgZWxjxX1kCF3FesDXxwcj+QLjGGpFSud5nDbay+K6lC/A8=" Aug 31 15:58:28 bcik go-librespot[28926]: time="2026-08-31T15:58:28+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:58:28 bcik volumio[28614]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:58:28 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:28 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:28 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:29 bcik volumio[28614]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:58:29 bcik volumio[28614]: info: Initializing connection to go-librespot Websocket Aug 31 15:58:29 bcik go-librespot[28926]: time="2026-08-31T15:58:29+02:00" level=debug msg="new websocket client" Aug 31 15:58:29 bcik volumio[28614]: info: Connection to go-librespot Websocket established Aug 31 15:58:29 bcik go-librespot[28926]: time="2026-08-31T15:58:29+02:00" level=debug msg="completed keyexchange" Aug 31 15:58:29 bcik go-librespot[28926]: time="2026-08-31T15:58:29+02:00" level=debug msg="completed challenge" Aug 31 15:58:29 bcik go-librespot[28926]: time="2026-08-31T15:58:29+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:58:29 bcik go-librespot[28926]: time="2026-08-31T15:58:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:58:29 bcik volumio[28614]: info: Connection to go-librespot Websocket closed Aug 31 15:58:29 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:58:29 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:58:29 bcik volumio[28614]: info: Updating MyVolumio device info Aug 31 15:58:29 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:29 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:29 bcik volumio[28614]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:58:30 bcik volumio[28614]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:58:32 bcik volumio[28614]: info: Getting Spotify volume Aug 31 15:58:32 bcik volumio[28614]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:58:32 bcik volumio[28614]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:58:32 bcik volumio[28614]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 15:58:32 bcik volumio[28614]: errno: -111, Aug 31 15:58:32 bcik volumio[28614]: code: 'ECONNREFUSED', Aug 31 15:58:32 bcik volumio[28614]: syscall: 'connect', Aug 31 15:58:32 bcik volumio[28614]: address: '127.0.0.1', Aug 31 15:58:32 bcik volumio[28614]: port: 9879, Aug 31 15:58:32 bcik volumio[28614]: response: undefined Aug 31 15:58:32 bcik volumio[28614]: } Aug 31 15:58:32 bcik volumio[28614]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:58:32 bcik sudo[28950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:57' Aug 31 15:58:32 bcik sudo[28950]: 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"