Dec 05 17:58:16 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 17:58:16 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 05 17:58:21 living-room volumio[1141]: info: Disabling plugin podcast Dec 05 17:58:21 living-room volumio[1141]: info: Done. Dec 05 17:58:24 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:58:25 living-room go-librespot[3391]: time="2025-12-05T17:58:25+01:00" level=trace msg="sent dealer ping" Dec 05 17:58:25 living-room go-librespot[3391]: time="2025-12-05T17:58:25+01:00" level=trace msg="received dealer pong" Dec 05 17:58:50 living-room volumio[1141]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 05 17:58:50 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 05 17:58:50 living-room volumio[1141]: info: Creating Spotify config file Dec 05 17:58:50 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 17:58:50 living-room volumio[1141]: info: Spotify config file written Dec 05 17:58:50 living-room sudo[5899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 17:58:50 living-room sudo[5899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:58:50 living-room systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 05 17:58:50 living-room systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 05 17:58:50 living-room volumio[1141]: info: Connection to go-librespot Websocket closed Dec 05 17:58:50 living-room systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:50 living-room systemd[1]: go-librespot-daemon.service: Consumed 2.644s CPU time. Dec 05 17:58:50 living-room volumio[1141]: info: Connection to go-librespot Websocket closed Dec 05 17:58:50 living-room go-librespot[5901]: go-librespot daemon starting... Dec 05 17:58:50 living-room sudo[5899]: pam_unix(sudo:session): session closed for user root Dec 05 17:58:50 living-room systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:50 living-room go-librespot[5902]: time="2025-12-05T17:58:50+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:58:50 living-room go-librespot[5902]: time="2025-12-05T17:58:50+01:00" level=debug msg="app state loaded" Dec 05 17:58:50 living-room go-librespot[5902]: time="2025-12-05T17:58:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:58:51 living-room go-librespot[5902]: time="2025-12-05T17:58:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 05 17:58:51 living-room go-librespot[5902]: time="2025-12-05T17:58:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 05 17:58:51 living-room go-librespot[5902]: time="2025-12-05T17:58:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 05 17:58:51 living-room go-librespot[5902]: time="2025-12-05T17:58:51+01:00" level=info msg="zeroconf server listening on port 45427" Dec 05 17:58:51 living-room go-librespot[5902]: time="2025-12-05T17:58:51+01:00" level=debug msg="obtained new client token: AADqpRDSBchXKhys9vJscO/8mqOFq+U4TTSo90Roe66B4FUai2Tkeaf3Ej+GnvT3+I5VoT+xX+xqRr6lCNKEbhN4IedGdSqhr4fHYvaWwfhpm+JJRqUE7lG3ZKSwMc6VsNi7lwjYcZ9G/gliI27sL8E8TeN7dU/l1NwcS8QGfVBGwevB7NrAu7Yjig+8MCRUqHYblS7SOGFAToW0Stba8iyKU+vfPLRQVPujMJ1vy1xeTgt/ZNQnLm82" Dec 05 17:58:51 living-room go-librespot[5902]: time="2025-12-05T17:58:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 05 17:58:51 living-room go-librespot[5902]: time="2025-12-05T17:58:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 05 17:58:51 living-room systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 17:58:51 living-room systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 17:58:53 living-room volumio[1141]: info: Initializing connection to go-librespot Websocket Dec 05 17:58:53 living-room volumio[1141]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 17:58:53 living-room volumio[1141]: info: go-librespot daemon successfully initialized Dec 05 17:58:54 living-room systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 05 17:58:54 living-room systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:54 living-room systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:54 living-room go-librespot[5925]: go-librespot daemon starting... Dec 05 17:58:54 living-room go-librespot[5926]: time="2025-12-05T17:58:54+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:58:54 living-room go-librespot[5926]: time="2025-12-05T17:58:54+01:00" level=debug msg="app state loaded" Dec 05 17:58:54 living-room go-librespot[5926]: time="2025-12-05T17:58:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:58:55 living-room go-librespot[5926]: time="2025-12-05T17:58:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:58:55 living-room go-librespot[5926]: time="2025-12-05T17:58:55+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:58:55 living-room go-librespot[5926]: time="2025-12-05T17:58:55+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:58:55 living-room go-librespot[5926]: time="2025-12-05T17:58:55+01:00" level=info msg="zeroconf server listening on port 37107" Dec 05 17:58:55 living-room go-librespot[5926]: time="2025-12-05T17:58:55+01:00" level=debug msg="obtained new client token: AADQghkiMtdh6fWYN5B7BsYJ8CPjiwg6Q9r6Im/Q1yPZ9L6FIpxhLHbKCn58wGKC+hDyU+H8oflp1uzavU1VrM+C1IYhu/Mb+lrFg2qaIi8O30ZDtCy3fGe/yBB7LPs5uJp45TBbH6/NhNocROnaP6DvFoqvTPFGrtu9b7qlqrAp5Az7OFX/jg6VstHdKhwBfp1RSHPz/5CupCNpyekUSuHzSaK2NMoLl7KqPTcg6KqA4gQ+TvuCC8Rt" Dec 05 17:58:55 living-room go-librespot[5926]: time="2025-12-05T17:58:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 05 17:58:55 living-room go-librespot[5926]: time="2025-12-05T17:58:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 05 17:58:55 living-room systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 17:58:55 living-room systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 17:58:56 living-room volumio[1141]: info: Initializing connection to go-librespot Websocket Dec 05 17:58:56 living-room volumio[1141]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 17:58:56 living-room volumio[1141]: info: Initializing connection to go-librespot Websocket Dec 05 17:58:56 living-room volumio[1141]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 17:58:56 living-room volumio[1141]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 05 17:58:56 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 05 17:58:56 living-room volumio[1141]: info: Creating Spotify config file Dec 05 17:58:56 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 17:58:56 living-room volumio[1141]: info: Spotify config file written Dec 05 17:58:56 living-room sudo[5935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 17:58:56 living-room sudo[5935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:58:57 living-room systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:57 living-room systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:57 living-room go-librespot[5937]: go-librespot daemon starting... Dec 05 17:58:57 living-room sudo[5935]: pam_unix(sudo:session): session closed for user root Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=debug msg="app state loaded" Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=info msg="zeroconf server listening on port 37711" Dec 05 17:58:57 living-room volumio[1141]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 05 17:58:57 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 05 17:58:57 living-room volumio[1141]: info: Creating Spotify config file Dec 05 17:58:57 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 17:58:57 living-room volumio[1141]: info: Spotify config file written Dec 05 17:58:57 living-room go-librespot[5938]: time="2025-12-05T17:58:57+01:00" level=debug msg="obtained new client token: AABwFNu2MDW06clUZqCH1R2aBF7OFbAWgTW/npt3sl3+OBRGYzbbWiVgwc3vQM89GIdd3jzZsN1GY9FuTdmNgBB6l5YQ9UP504Yrp1LRN4JzkTZRKchEIJq/+dQs3zLxFiohA0hb826KD4Yjojhlr1jCn2/dptNW2hMV3wJBdZHpGNOL47XoAoIM8TLAcS4zV4h4ivwppvBKB9Lv6mXUkjePaNrDf3+hQU4e3z20z2l7FwNstnxXaiaN" Dec 05 17:58:57 living-room sudo[5946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 17:58:57 living-room sudo[5946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:58:57 living-room systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 05 17:58:57 living-room systemd[1]: go-librespot-daemon.service: Killing process 5940 (go-librespot) with signal SIGKILL. Dec 05 17:58:57 living-room systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 05 17:58:57 living-room systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:57 living-room systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:58:57 living-room go-librespot[5948]: go-librespot daemon starting... Dec 05 17:58:57 living-room sudo[5946]: pam_unix(sudo:session): session closed for user root Dec 05 17:58:57 living-room go-librespot[5950]: time="2025-12-05T17:58:57+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:58:57 living-room go-librespot[5950]: time="2025-12-05T17:58:57+01:00" level=debug msg="app state loaded" Dec 05 17:58:57 living-room go-librespot[5950]: time="2025-12-05T17:58:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:58:58 living-room go-librespot[5950]: time="2025-12-05T17:58:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:58:58 living-room go-librespot[5950]: time="2025-12-05T17:58:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:58:58 living-room go-librespot[5950]: time="2025-12-05T17:58:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:58:58 living-room go-librespot[5950]: time="2025-12-05T17:58:58+01:00" level=info msg="zeroconf server listening on port 46369" Dec 05 17:58:58 living-room go-librespot[5950]: time="2025-12-05T17:58:58+01:00" level=debug msg="obtained new client token: AAC4m8rCdp68I7W9wA9uh/IWEgv/jG71xwtlqKtts3HP1XwHMOwVyJzYiAX1Mx205Gu8IeW0PWcQqoQqyFvmjTXnqeQ6ygZtmk/zaQvJI060ndYlfeOiwD9B1ZIr3ty/69K0G0dw1qskiG4IZGb0nzqgt/uyRJDNQIzuCJPPeB88MKTa8R8urn6xHziSgAs6R+EVQ9rBMF8x9tIrkSDnoc61oer3iWlKMW534jT3QM5c1mcoB3k3n6qN" Dec 05 17:58:58 living-room go-librespot[5950]: time="2025-12-05T17:58:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 05 17:58:58 living-room go-librespot[5950]: time="2025-12-05T17:58:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 05 17:58:58 living-room systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 17:58:58 living-room systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 17:58:59 living-room volumio[1141]: info: Initializing connection to go-librespot Websocket Dec 05 17:58:59 living-room volumio[1141]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 17:59:00 living-room volumio[1141]: info: go-librespot daemon successfully initialized Dec 05 17:59:00 living-room volumio[1141]: info: go-librespot daemon successfully initialized Dec 05 17:59:01 living-room systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 05 17:59:01 living-room systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:59:01 living-room systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:59:01 living-room go-librespot[5962]: go-librespot daemon starting... Dec 05 17:59:01 living-room go-librespot[5963]: time="2025-12-05T17:59:01+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:59:01 living-room go-librespot[5963]: time="2025-12-05T17:59:01+01:00" level=debug msg="app state loaded" Dec 05 17:59:01 living-room go-librespot[5963]: time="2025-12-05T17:59:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=info msg="zeroconf server listening on port 36711" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="obtained new client token: AAAfKW0NbayAzvHF+Othy6oh6PH4W31tSWEDF5KvSjE9owoqYUweL+Bat8vHjD8BHZPE0iHd346sr6S9/Da2219pT2sB/cp/4NRJWCfwU9LTc4BWHTxtvzXQlds0uTGIAnzZod696yYaFx5Zv3VeJJ1PjA2oZbWSOYlCIQuiLB2KSiyh/HVnhAXDF71ipY4IFwvqIh4t/Kf6Sv5HuKp2YBhhSbNv2dIsvYwd/MzvIsWNbHHouPL+ew==" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="completed keyexchange" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="completed challenge" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=info msg="authenticated AP" username="31************************mq" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=info msg="authenticated Login5" username="31************************mq" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="initializing zeroconf session" username="31************************mq" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="dealer connection opened" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=trace msg="starting accesspoint recv loop" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=trace msg="starting dealer recv loop" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=trace msg="received accesspoint ping" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="received connection id: M2JjOTc0ZTUtMWVj...NjlEQTQzMDFEMA==" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=trace msg="received accesspoint pong ack" Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 05 17:59:02 living-room volumio[1141]: info: Initializing connection to go-librespot Websocket Dec 05 17:59:02 living-room go-librespot[5963]: time="2025-12-05T17:59:02+01:00" level=debug msg="new websocket client" Dec 05 17:59:02 living-room volumio[1141]: info: Connection to go-librespot Websocket established Dec 05 17:59:03 living-room volumio[1141]: info: Initializing connection to go-librespot Websocket Dec 05 17:59:03 living-room go-librespot[5963]: time="2025-12-05T17:59:03+01:00" level=debug msg="new websocket client" Dec 05 17:59:03 living-room volumio[1141]: info: Connection to go-librespot Websocket established Dec 05 17:59:03 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 17:59:03 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 05 17:59:03 living-room volumio[1141]: info: Initializing connection to go-librespot Websocket Dec 05 17:59:03 living-room go-librespot[5963]: time="2025-12-05T17:59:03+01:00" level=debug msg="new websocket client" Dec 05 17:59:03 living-room volumio[1141]: info: Connection to go-librespot Websocket established Dec 05 17:59:05 living-room volumio[1141]: info: Getting Spotify volume Dec 05 17:59:05 living-room volumio[1141]: info: Spotify volume: 100 Dec 05 17:59:05 living-room volumio[1141]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 05 17:59:06 living-room volumio[1141]: info: CoreCommandRouter::volumioGetState Dec 05 17:59:06 living-room volumio[1141]: info: CorePlayQueue::getTrack 4 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: SPOTIFY VOLUME 100 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: VOLUMIO VOLUME 29 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 05 17:59:06 living-room volumio[1141]: info: Setting Spotify Volume from Volumio: 29 Dec 05 17:59:06 living-room volumio[1141]: info: Getting Spotify volume Dec 05 17:59:06 living-room volumio[1141]: info: Spotify volume: 100 Dec 05 17:59:06 living-room volumio[1141]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 05 17:59:06 living-room volumio[1141]: info: CoreCommandRouter::volumioGetState Dec 05 17:59:06 living-room volumio[1141]: info: CorePlayQueue::getTrack 4 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: SPOTIFY VOLUME 100 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: VOLUMIO VOLUME 29 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 05 17:59:06 living-room volumio[1141]: info: Setting Spotify Volume from Volumio: 29 Dec 05 17:59:06 living-room volumio[1141]: info: Getting Spotify volume Dec 05 17:59:06 living-room volumio[1141]: info: Spotify volume: 100 Dec 05 17:59:06 living-room volumio[1141]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 05 17:59:06 living-room volumio[1141]: info: CoreCommandRouter::volumioGetState Dec 05 17:59:06 living-room volumio[1141]: info: CorePlayQueue::getTrack 4 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: SPOTIFY VOLUME 100 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: VOLUMIO VOLUME 29 Dec 05 17:59:06 living-room volumio[1141]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 05 17:59:06 living-room volumio[1141]: info: Setting Spotify Volume from Volumio: 29 Dec 05 17:59:08 living-room volumio[1141]: SPOTIFY: SETTING SPOTIFY VOLUME 29 Dec 05 17:59:08 living-room volumio[1141]: info: Sending Spotify command with payload to local API: /player/volume Dec 05 17:59:08 living-room go-librespot[5963]: time="2025-12-05T17:59:08+01:00" level=debug msg="update volume requested to 19005/65535" Dec 05 17:59:08 living-room go-librespot[5963]: time="2025-12-05T17:59:08+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 17:59:08 living-room go-librespot[5963]: time="2025-12-05T17:59:08+01:00" level=trace msg="emitting websocket event: volume" Dec 05 17:59:08 living-room volumio[1141]: SPOTIFY: received: {"type":"volume","data":{"value":29,"max":100}} Dec 05 17:59:08 living-room volumio[1141]: SPOTIFY: RECEIVED SPOTIFY VOLUME 29 Dec 05 17:59:08 living-room volumio[1141]: SPOTIFY: received: {"type":"volume","data":{"value":29,"max":100}} Dec 05 17:59:08 living-room volumio[1141]: SPOTIFY: RECEIVED SPOTIFY VOLUME 29 Dec 05 17:59:08 living-room volumio[1141]: SPOTIFY: received: {"type":"volume","data":{"value":29,"max":100}} Dec 05 17:59:08 living-room volumio[1141]: SPOTIFY: RECEIVED SPOTIFY VOLUME 29 Dec 05 17:59:19 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:59:19 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 05 17:59:19 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 05 17:59:19 living-room sudo[6009]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 05 17:59:19 living-room sudo[6009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:59:19 living-room sudo[6014]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 05 17:59:19 living-room sudo[6014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:59:19 living-room sudo[6009]: pam_unix(sudo:session): session closed for user root Dec 05 17:59:19 living-room sudo[6014]: pam_unix(sudo:session): session closed for user root Dec 05 17:59:19 living-room sudo[6020]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 05 17:59:19 living-room sudo[6020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:59:19 living-room sudo[6020]: pam_unix(sudo:session): session closed for user root Dec 05 17:59:19 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Dec 05 17:59:19 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Dec 05 17:59:19 living-room sudo[6027]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 05 17:59:19 living-room sudo[6027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:59:19 living-room sudo[6027]: pam_unix(sudo:session): session closed for user root Dec 05 17:59:19 living-room sudo[6033]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 17:59:19 living-room sudo[6033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:59:20 living-room sudo[6033]: pam_unix(sudo:session): session closed for user root Dec 05 17:59:20 living-room sudo[6036]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 17:59:20 living-room sudo[6036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:59:20 living-room sudo[6036]: pam_unix(sudo:session): session closed for user root Dec 05 17:59:25 living-room dhcpcd[704]: eth0: failed to renew DHCP, rebinding Dec 05 17:59:25 living-room dhcpcd[704]: eth0: leased 192.168.63.81 for 600 seconds Dec 05 17:59:25 living-room systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 05 17:59:25 living-room systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 05 17:59:25 living-room systemd[1]: welcome.service: Deactivated successfully. Dec 05 17:59:25 living-room systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 05 17:59:25 living-room systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 05 17:59:25 living-room systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 05 17:59:25 living-room welcome[6075]: Resolved ip:[1] 192.168.63.81 Dec 05 17:59:25 living-room systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 05 17:59:25 living-room systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 05 17:59:32 living-room go-librespot[5963]: time="2025-12-05T17:59:32+01:00" level=trace msg="sent dealer ping" Dec 05 17:59:32 living-room go-librespot[5963]: time="2025-12-05T17:59:32+01:00" level=trace msg="received dealer pong" Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:59:44 living-room volumio[1141]: info: Retrieving Cloud Streaming UI Dec 05 17:59:44 living-room volumio[1141]: info: Getting Tidal Cloud Configuration Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:59:44 living-room volumio[1141]: info: Getting Qobuz Cloud Configuration Dec 05 17:59:44 living-room volumio[1141]: info: Asking plugin for UI Config Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:59:44 living-room volumio[1141]: info: Getting Spotify Cloud Configuration Dec 05 17:59:44 living-room volumio[1141]: info: Asking plugin for UI Config Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:59:44 living-room volumio[1141]: info: Saving Spotify Acccount Dec 05 17:59:44 living-room volumio[1141]: info: Got Tidal Cloud Configuration Dec 05 17:59:44 living-room volumio[1141]: info: Got it Dec 05 17:59:44 living-room volumio[1141]: info: Got it Dec 05 17:59:44 living-room volumio[1141]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:59:44 living-room volumio[1141]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::volumioGetBrowseSources Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::volumioGetBrowseSources Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::volumioGetBrowseSources Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 05 17:59:44 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 05 17:59:48 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 05 17:59:52 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 05 17:59:52 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Dec 05 17:59:52 living-room volumio[1141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Dec 05 17:59:53 living-room volumio[1141]: compat.c: read() failed: Resource temporarily unavailable Dec 05 17:59:53 living-room volumio[1141]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 17:59:53 living-room volumio[1141]: Error: dns service error: unknown Dec 05 17:59:53 living-room volumio[1141]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Dec 05 17:59:53 living-room volumio[1141]: errorCode: -65537 Dec 05 17:59:53 living-room volumio[1141]: } Dec 05 17:59:53 living-room volumio[1141]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 17:59:54 living-room sudo[6143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 17:58' Dec 05 17:59:54 living-room sudo[6143]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"