-- Logs begin at Mon 2025-03-17 20:20:47 CET, end at Mon 2025-03-17 22:27:45 CET. -- Mar 17 22:26:29 volumio volumio[836]: info: CALLMETHOD: music_service minidlna forceRescan R Mar 17 22:26:29 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: minidlna , forceRescan Mar 17 22:26:29 volumio sudo[18827]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e s/^Environment=DAEMON_OPTS=$/Environment=DAEMON_OPTS=-R/ /etc/systemd/system/minidlna.service Mar 17 22:26:29 volumio sudo[18827]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:29 volumio sudo[18827]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:29 volumio sudo[18830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 17 22:26:29 volumio sudo[18830]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:29 volumio sudo[18830]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:29 volumio volumio[836]: error: minidlna: Failed to daemon-reload: Error: Command failed: /usr/bin/sudo /bin/systemctl daemon-reload Mar 17 22:26:29 volumio volumio[836]: Failed to reload daemon: Refusing to reload, not enough space available on /run/systemd. Currently, 10.6M are free, but a safety buffer of 16.0M is enforced. Mar 17 22:26:36 volumio volumio[836]: info: CALLMETHOD: music_service minidlna forceRescan R Mar 17 22:26:36 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: minidlna , forceRescan Mar 17 22:26:36 volumio sudo[18851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e s/^Environment=DAEMON_OPTS=$/Environment=DAEMON_OPTS=-R/ /etc/systemd/system/minidlna.service Mar 17 22:26:36 volumio sudo[18851]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:36 volumio sudo[18851]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:36 volumio sudo[18854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 17 22:26:36 volumio sudo[18854]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:36 volumio sudo[18854]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:36 volumio volumio[836]: error: minidlna: Failed to daemon-reload: Error: Command failed: /usr/bin/sudo /bin/systemctl daemon-reload Mar 17 22:26:36 volumio volumio[836]: Failed to reload daemon: Refusing to reload, not enough space available on /run/systemd. Currently, 10.6M are free, but a safety buffer of 16.0M is enforced. Mar 17 22:26:43 volumio go-librespot[17885]: time="2025-03-17T22:26:43+01:00" level=error msg="did not receive last pong ack from accesspoint, 120s passed" Mar 17 22:26:43 volumio go-librespot[17885]: time="2025-03-17T22:26:43+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: read tcp 192.168.50.64:52654->34.158.1.133:4070: use of closed network connection" Mar 17 22:26:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:26:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:26:43 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 17 22:26:43 volumio volumio[836]: at connResetException (internal/errors.js:607:14) Mar 17 22:26:43 volumio volumio[836]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 17 22:26:43 volumio volumio[836]: at Socket.emit (events.js:327:22) Mar 17 22:26:43 volumio volumio[836]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 17 22:26:43 volumio volumio[836]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 17 22:26:43 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 11258) Mar 17 22:26:43 volumio volumio[836]: info: Connection to go-librespot Websocket closed Mar 17 22:26:46 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:26:46 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:26:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:26:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33548. Mar 17 22:26:46 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:26:46 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:26:46 volumio go-librespot[18872]: Librespot-go daemon starting... Mar 17 22:26:46 volumio go-librespot[18872]: time="2025-03-17T22:26:46+01:00" level=info msg="generated new device id: 22fe9938c41017a67d1c70e9cbab42c40d139ce3" Mar 17 22:26:46 volumio go-librespot[18872]: time="2025-03-17T22:26:46+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+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]" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+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]" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+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]" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+01:00" level=debug msg="zeroconf server listening on port 36963" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+01:00" level=debug msg="obtained new client token: AAC2SlrmwQAsF1h59xTVh7GWGnf8QvLj+R62v/aOu14eSX3qT6WCt+N9z3uv2Wuujx5YuCgW+x0A3GJJeRXZUYTaNQG3pLP6iSEthlunSRkKr4EDpFgMK8ozD2wRoR3RjhXCVSmaazW/4r3pjIhB2X03A+H6k1lmBTefWOGXdMkiFojY2pFL15ZiC/tRUW6mkKc8jrqxPfnJYZSiNfjYoYxSFWG6FluPpsafIjWAG8KyBR+4HjIIzoEH41b4" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+01:00" level=debug msg="completed keyexchange" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+01:00" level=debug msg="completed challenge" Mar 17 22:26:47 volumio go-librespot[18872]: time="2025-03-17T22:26:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:26:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:26:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:26:49 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:26:49 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:26:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:26:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33549. Mar 17 22:26:50 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:26:51 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:26:51 volumio go-librespot[18881]: Librespot-go daemon starting... Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+01:00" level=info msg="generated new device id: 7e91ccbdaf24e2ad7c57770560f98cbc3cb1d1cc" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26: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-gae2.spotify.com:80]" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+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]" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+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]" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+01:00" level=debug msg="zeroconf server listening on port 46421" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+01:00" level=debug msg="obtained new client token: AADe9vHS8DGPh5NWrqjOT4uM+I42ELm+TFzMs5qJlEk6V/28WkB+jp8V59zpA+cfrd06Mk1AUcdceCfWoCS+QmPMli3YL6I5q3LBCyBrD0oqFxjjOOW3O9HtIRDJN9311jqgOApq2uQ/LUGUClocL6m/Qwz9AVoslTijvxah2s04gNEPiN3FAArBRBIW9ycc6WuBGYkO8w9eUEdyoNBNhQl/QITlwG0UYikDxOd8w+ewh0jirx+e2KNq0+UpEIA=" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:26:51 volumio go-librespot[18881]: time="2025-03-17T22:26:51+01:00" level=debug msg="completed keyexchange" Mar 17 22:26:52 volumio go-librespot[18881]: time="2025-03-17T22:26:52+01:00" level=debug msg="completed challenge" Mar 17 22:26:52 volumio go-librespot[18881]: time="2025-03-17T22:26:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:26:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:26:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:26:52 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:26:52 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:26:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:26:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33550. Mar 17 22:26:55 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:26:55 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:26:55 volumio go-librespot[18906]: Librespot-go daemon starting... Mar 17 22:26:55 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26:55+01:00" level=info msg="generated new device id: 0e7dca919a0d1b7594e689bea4517e0971f6cfce" Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26:55+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:26:55 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:26:55 volumio volumio[836]: info: CALLMETHOD: music_service minidlna forceRescan r Mar 17 22:26:55 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: minidlna , forceRescan Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26: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]" Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26: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]" Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26: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]" Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26:55+01:00" level=debug msg="zeroconf server listening on port 38147" Mar 17 22:26:55 volumio sudo[18916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e s/^Environment=DAEMON_OPTS=$/Environment=DAEMON_OPTS=-r/ /etc/systemd/system/minidlna.service Mar 17 22:26:55 volumio sudo[18916]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26:55+01:00" level=debug msg="obtained new client token: AADIBZq3amLaXHSpXjz+9/mOKv6WWRAdi8kH0m4gnE7hwKQSL3euX8deotn7IPdXGpgb/sD1t1s7qQd9s09pOMpQrWFOHpUOydnRLF4mitd4+xUm6kRvMQIi/+pas/ZCglMU6PnHxBfu0GQnhNCvyV7PDMAsYqZJAoTzfvDJ50mJj1PV5vvkn7z6az/+kwUUtwYoSgSbsqzmIrepdnGh+U2Jzmc6e6Qgj3Fjsz8zetHYkGNdRJY0gMyEFYmsPF4=" Mar 17 22:26:55 volumio sudo[18916]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:55 volumio sudo[18919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 17 22:26:55 volumio sudo[18919]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26:55+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:26:55 volumio sudo[18919]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:55 volumio volumio[836]: error: minidlna: Failed to daemon-reload: Error: Command failed: /usr/bin/sudo /bin/systemctl daemon-reload Mar 17 22:26:55 volumio volumio[836]: Failed to reload daemon: Refusing to reload, not enough space available on /run/systemd. Currently, 10.6M are free, but a safety buffer of 16.0M is enforced. Mar 17 22:26:55 volumio go-librespot[18906]: time="2025-03-17T22:26:55+01:00" level=debug msg="completed keyexchange" Mar 17 22:26:56 volumio go-librespot[18906]: time="2025-03-17T22:26:56+01:00" level=debug msg="completed challenge" Mar 17 22:26:56 volumio go-librespot[18906]: time="2025-03-17T22:26:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:26:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:26:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:26:56 volumio volumio[836]: info: CALLMETHOD: music_service minidlna forceRescan R Mar 17 22:26:56 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: minidlna , forceRescan Mar 17 22:26:57 volumio sudo[18979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e s/^Environment=DAEMON_OPTS=$/Environment=DAEMON_OPTS=-R/ /etc/systemd/system/minidlna.service Mar 17 22:26:57 volumio sudo[18979]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:57 volumio sudo[18979]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:57 volumio sudo[18982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 17 22:26:57 volumio sudo[18982]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:26:57 volumio sudo[18982]: pam_unix(sudo:session): session closed for user root Mar 17 22:26:57 volumio volumio[836]: error: minidlna: Failed to daemon-reload: Error: Command failed: /usr/bin/sudo /bin/systemctl daemon-reload Mar 17 22:26:57 volumio volumio[836]: Failed to reload daemon: Refusing to reload, not enough space available on /run/systemd. Currently, 10.6M are free, but a safety buffer of 16.0M is enforced. Mar 17 22:26:58 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:26:58 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:26:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:26:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33551. Mar 17 22:26:59 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:26:59 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:26:59 volumio go-librespot[18984]: Librespot-go daemon starting... Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+01:00" level=info msg="generated new device id: 648b34a370bc33de48ddeb3325fcac1d7be6317f" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+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]" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+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]" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+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]" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+01:00" level=debug msg="zeroconf server listening on port 42049" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+01:00" level=debug msg="obtained new client token: AAAeicyCsqaN3Sr+MV+QVZGbJiaiBvFpEHvwOllRoZPAa0Cgs//CyBmQEp1bCr4BL84nAVrM0I2c6xhFI14Fewl3PFTEuxOH6Wyveg6E0IXOe+ffh83HfIKrmy73P7cenKqFPkyXWgaIgBeo/e6lB6o8hu4dbUQ+jWLHybEDcyFz1mNBSrC+HAmh72Dcn+fhLCIMCwxzRFVbyVUuM2SxUx7MtUQz6yGL0SBasUVhRCCl973th5+dxa8rZANzsDU=" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:26:59 volumio go-librespot[18984]: time="2025-03-17T22:26:59+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:00 volumio go-librespot[18984]: time="2025-03-17T22:27:00+01:00" level=debug msg="completed challenge" Mar 17 22:27:00 volumio go-librespot[18984]: time="2025-03-17T22:27:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:01 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:01 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33552. Mar 17 22:27:03 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:03 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:03 volumio go-librespot[19006]: Librespot-go daemon starting... Mar 17 22:27:03 volumio go-librespot[19006]: time="2025-03-17T22:27:03+01:00" level=info msg="generated new device id: 9abbd94ac3c717c73a3d6bd6adcaa8eb3aa8892a" Mar 17 22:27:03 volumio go-librespot[19006]: time="2025-03-17T22:27:03+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+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]" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+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]" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+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]" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+01:00" level=debug msg="zeroconf server listening on port 37849" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+01:00" level=debug msg="obtained new client token: AABNEnFlGuD76xfBVQblSItXh3rrU0Kvar6CWExBHaUO600OnvzeSRgUb5YCYgCQhh0fEGtED/Tu5x9Th0SFopPm6U9lkJ8ZXABGoDR2Pv73hCysF28XRkZ9sPaJtDzJAkupJtJhqO2eNnjPwfERvinRrIxf/usWdhEqP3dt/+ApO27INSX3QxSeXB+EMrhcmV8+kPc/FQg8V2CKOJj+N7yoFEdMSkooEeLS5q2EIPho37QH5XMFCMjpP1iL" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:04 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+01:00" level=debug msg="new websocket client" Mar 17 22:27:04 volumio volumio[836]: info: Connection to go-librespot Websocket established Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+01:00" level=debug msg="completed challenge" Mar 17 22:27:04 volumio go-librespot[19006]: time="2025-03-17T22:27:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:04 volumio volumio[836]: info: Connection to go-librespot Websocket closed Mar 17 22:27:07 volumio volumio[836]: info: Getting Spotify volume Mar 17 22:27:07 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:07 volumio volumio[836]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 17 22:27:07 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 11259) Mar 17 22:27:07 volumio volumio[836]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 17 22:27:07 volumio volumio[836]: info: CoreCommandRouter::volumioGetState Mar 17 22:27:07 volumio volumio[836]: info: CorePlayQueue::getTrack 0 Mar 17 22:27:07 volumio volumio[836]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Mar 17 22:27:07 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:07 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33553. Mar 17 22:27:07 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:07 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:08 volumio go-librespot[19015]: Librespot-go daemon starting... Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=info msg="generated new device id: 54c8bc1be334f60675a058447c2a676f160f71da" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+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]" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+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]" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+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]" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=debug msg="zeroconf server listening on port 45827" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=debug msg="obtained new client token: AADnf9n2n4a0ODTnrNGSewiFTE89QaegPLUUTUUewtNFu1UfZ1iEDVKHzDbWhTbLBAfMyfwCJ4nQ2hmc440d2rkedWyNueMVlXTwdhIUH5DQI/8Utf9mZMAva6O6YgXoo4CQVu1WyarRA6czqB/58sT9Ac1FZzfNDDeEQmxkjeRRZcjrpuWvyF2Xq6sDEQr3QURaOzbN11+ZOuYFgGBRzyZs14B9d2OkxnPplofG1XlcTFLeTLqNsvhTDbG/eDA=" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=debug msg="completed challenge" Mar 17 22:27:08 volumio go-librespot[19015]: time="2025-03-17T22:27:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:10 volumio volumio[836]: info: Tunnel connection is inactive, restarting it Mar 17 22:27:10 volumio volumio[836]: info: Starting Tunnel 1 Mar 17 22:27:10 volumio volumio[836]: info: Starting Tunnel Connection Checker Mar 17 22:27:10 volumio sudo[19028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 17 22:27:10 volumio sudo[19028]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 22:27:10 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Mar 17 22:27:10 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Mar 17 22:27:10 volumio volumio[836]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 17 22:27:10 volumio autossh[18357]: received signal to exit (15) Mar 17 22:27:10 volumio systemd[1]: sshtunnel.service: Succeeded. Mar 17 22:27:10 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. Mar 17 22:27:10 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:10 volumio volumio[836]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 17 22:27:10 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:10 volumio systemd[1]: Started MyVolumio SSH Tunnel. Mar 17 22:27:10 volumio sudo[19028]: pam_unix(sudo:session): session closed for user root Mar 17 22:27:10 volumio volumio[836]: info: Remote SSH Started Mar 17 22:27:10 volumio autossh[19031]: port set to 0, monitoring disabled Mar 17 22:27:10 volumio autossh[19031]: starting ssh (count 1) Mar 17 22:27:10 volumio autossh[19031]: ssh child pid is 19034 Mar 17 22:27:10 volumio volumio[836]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 17 22:27:10 volumio volumio[836]: info: CoreCommandRouter::volumioGetState Mar 17 22:27:10 volumio volumio[836]: info: CorePlayQueue::getTrack 0 Mar 17 22:27:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33554. Mar 17 22:27:12 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:12 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:12 volumio go-librespot[19052]: Librespot-go daemon starting... Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+01:00" level=info msg="generated new device id: 00f22fe4a0b6cd1198d5a0a3b456f5c34ea19491" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+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]" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+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]" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+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]" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+01:00" level=debug msg="zeroconf server listening on port 34085" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+01:00" level=debug msg="obtained new client token: AABGU57xHyexTf812+wboP8MyNdohQe44SqNV5tUZSIFkkAra7HpPLAJvGHax0KXBJsDp/U9RYgybcA/UHtGkAqT8+SnT7//ys4lzMTmfchBMHE2N3Eoqdc/Ucykx6D85M97Ij/PxShPh2G0d56bOWl6E7yewIqoBHKq24qbdrAZl9cZnTsJ8JWqB50FOlEK7E60ok+dQJ9sauiZjO4mRLYFr2TjB7bzQ4AKUzdNBDQFIJmk8qESpV4juznn6QQ=" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:12 volumio go-librespot[19052]: time="2025-03-17T22:27:12+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:13 volumio go-librespot[19052]: time="2025-03-17T22:27:13+01:00" level=debug msg="completed challenge" Mar 17 22:27:13 volumio go-librespot[19052]: time="2025-03-17T22:27:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:13 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:13 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:14 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 22:27:14 volumio volumio[836]: info: Preload queue cleared Mar 17 22:27:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33555. Mar 17 22:27:16 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:16 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:16 volumio go-librespot[19060]: Librespot-go daemon starting... Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+01:00" level=info msg="generated new device id: 4cd672afe9d28073dfc359a2059bc84b6a5fc20d" Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+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]" Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+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]" Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+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]" Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+01:00" level=debug msg="zeroconf server listening on port 45073" Mar 17 22:27:16 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+01:00" level=debug msg="new websocket client" Mar 17 22:27:16 volumio volumio[836]: info: Connection to go-librespot Websocket established Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+01:00" level=debug msg="obtained new client token: AABzMqg/1+qRiL8BVNP87OgTKYtBoIDfUxt9pa66745Wc6l93TJ40JXL6pcbm05rV9XlqzzwqHLVS1foMbTviIGz3XZ2u7EZMIpKtQWr+uKKqHVR/1aTLUcNZ0Trqq+1oEyWPusqxdR46smFPKNhsv6H22qfxNnnpW0eqgq/kzv76/yZcko1wUzS4vCgwh85DQkHcCtxM1Ye7gZQV0atI81U0yVhKbLpBZTZUGNiNwaiTUI/ULVmlDKZnL67+bw=" Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:16 volumio go-librespot[19060]: time="2025-03-17T22:27:16+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:17 volumio go-librespot[19060]: time="2025-03-17T22:27:17+01:00" level=debug msg="completed challenge" Mar 17 22:27:17 volumio go-librespot[19060]: time="2025-03-17T22:27:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:17 volumio volumio[836]: info: Connection to go-librespot Websocket closed Mar 17 22:27:19 volumio volumio[836]: info: Getting Spotify volume Mar 17 22:27:19 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:19 volumio volumio[836]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 17 22:27:19 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 11260) Mar 17 22:27:19 volumio volumio[836]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 17 22:27:19 volumio volumio[836]: info: CoreCommandRouter::volumioGetState Mar 17 22:27:19 volumio volumio[836]: info: CorePlayQueue::getTrack 0 Mar 17 22:27:19 volumio volumio[836]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Mar 17 22:27:20 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:20 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33556. Mar 17 22:27:20 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:20 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:20 volumio go-librespot[19068]: Librespot-go daemon starting... Mar 17 22:27:20 volumio go-librespot[19068]: time="2025-03-17T22:27:20+01:00" level=info msg="generated new device id: c645bc8c9b816fb37862192bccef5c656a7545a8" Mar 17 22:27:20 volumio go-librespot[19068]: time="2025-03-17T22:27:20+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+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]" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+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]" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+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]" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=debug msg="zeroconf server listening on port 44459" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=debug msg="obtained new client token: AAAd2GWwILp14kL2Zs4by3E5GQXDXJhNJ2LyYbDqK02tXwFIxgpk9E0zT6vlendpy4ERBq8YZuQamp8KxKIkEwRkZ2s5nsUkBL0niB7IGk5LLq4jsnvcGqmJSOkZuLx9R23Wg/afWsVCtafpJEwyvzVNX/NcElopskE6teAmhUlRA9277Kw1iCsofmPU9lydSvZsLdpRSnfdCUw5vFEGVgrsp5E/n6zZXAdvUsfSuYcpEEn2ZNHMipcUJV/9" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443 (error: dial tcp 34.158.1.133:443: connect: connection refused), retrying with a different AP" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=info msg="connected to ap-gew4.spotify.com:80" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=debug msg="completed challenge" Mar 17 22:27:21 volumio go-librespot[19068]: time="2025-03-17T22:27:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:23 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:23 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33557. Mar 17 22:27:24 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:24 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:24 volumio go-librespot[19090]: Librespot-go daemon starting... Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+01:00" level=info msg="generated new device id: 6b1051e5d09ba0f4ad12ae676ec4e29d0b5dfaa4" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+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]" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+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]" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+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]" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+01:00" level=debug msg="zeroconf server listening on port 37651" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+01:00" level=debug msg="obtained new client token: AAA1mH8MGFpRPBXkoydl6+bZ2WUR1//tjJpmU6PDLpqs/h+akDu0QMca32p+0ie7s5TgGalvYt2EcWVPuAsefA5jyMC9+0rBuX9vbmtBkElcsnYuxaFExy6Zp/JI+vzXsXTRF9sHzUa6tLr2paLaMNC5hnkF0C50bcmGSD6sceZ3e9CWP1nTefZw9PTByPcS8Htj7L4f15CbW+VJ0jyRdxp9eOIPluod1XgMa0qloPfLq8/EEXfZpKgKT9x3Lcg=" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:25 volumio go-librespot[19090]: time="2025-03-17T22:27:25+01:00" level=debug msg="completed challenge" Mar 17 22:27:26 volumio go-librespot[19090]: time="2025-03-17T22:27:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:26 volumio volumiossh-tunnel[19030]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts. Mar 17 22:27:26 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:26 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:27 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 22:27:27 volumio volumio[836]: info: Preload queue cleared Mar 17 22:27:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33558. Mar 17 22:27:29 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:29 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:29 volumio go-librespot[19099]: Librespot-go daemon starting... Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+01:00" level=info msg="generated new device id: 54dabde146c377e4ec78262ba1df71171c743851" Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:29 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+01:00" level=debug msg="new websocket client" Mar 17 22:27:29 volumio volumio[836]: info: Connection to go-librespot Websocket established Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+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]" Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+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]" Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+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]" Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+01:00" level=debug msg="zeroconf server listening on port 44103" Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+01:00" level=debug msg="obtained new client token: AAC0Jk+LZAnXcFwYISyKtGIGOBAMnnevERrWW67a+gwd5/FFI4a/8K8F0S144L7weHcz4bT3qef7f9eTsJ43ZKp36g0v/XG+1T2Bd0u/26mzPQ+l0TFUEcWQSEvElzSU4B+9kf+lpFrX8T25ycSSqWVp2JnotVx/hKNCC29U73y4rUKzMVdHAVa0M5vDWCfVWv6s201e9V4bmIwvA/E+WgM87qEU7Wz3Y7IzEtXL+ID7JspuUOVekxsdUEUsgY4=" Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:29 volumio go-librespot[19099]: time="2025-03-17T22:27:29+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:30 volumio go-librespot[19099]: time="2025-03-17T22:27:30+01:00" level=debug msg="completed challenge" Mar 17 22:27:30 volumio go-librespot[19099]: time="2025-03-17T22:27:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:30 volumio volumio[836]: info: Connection to go-librespot Websocket closed Mar 17 22:27:32 volumio volumio[836]: info: Getting Spotify volume Mar 17 22:27:32 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:32 volumio volumio[836]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 17 22:27:32 volumio volumio[836]: (node:836) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 11261) Mar 17 22:27:32 volumio volumio[836]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 17 22:27:32 volumio volumio[836]: info: CoreCommandRouter::volumioGetState Mar 17 22:27:32 volumio volumio[836]: info: CorePlayQueue::getTrack 0 Mar 17 22:27:32 volumio volumio[836]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Mar 17 22:27:33 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:33 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33559. Mar 17 22:27:33 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:33 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:33 volumio go-librespot[19124]: Librespot-go daemon starting... Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+01:00" level=info msg="generated new device id: 3f722d28ba0d79f67277359b495ec86e0b0729e6" Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:33 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 22:27:33 volumio volumio[836]: info: Preload queue cleared Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+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]" Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+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]" Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+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]" Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+01:00" level=debug msg="zeroconf server listening on port 42667" Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+01:00" level=debug msg="obtained new client token: AACjZPPDX2LNT8GwVWo/dR6EU9ztM/MXn0ckuT6tVz09f6y4GjsU0gWCYFsy5szbyV1Ub5dokS31INvWmfV703EAvM1SeUUp+f7AjUXs4b0hSC1leoeIxXLqL7asJGgOYM7CWtu+/Tfi5sKh588agODic0WWdPC4VamgNTiA6a3UpTRNSf4i1W3J3hBAB7q1g6GeOzubvvkiAkyzdWYqZo+W0+xl4kwwim9XyZZ3/Mw6QRCKnX338NopXDDZXPw=" Mar 17 22:27:33 volumio go-librespot[19124]: time="2025-03-17T22:27:33+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:34 volumio go-librespot[19124]: time="2025-03-17T22:27:34+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:34 volumio go-librespot[19124]: time="2025-03-17T22:27:34+01:00" level=debug msg="completed challenge" Mar 17 22:27:34 volumio go-librespot[19124]: time="2025-03-17T22:27:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:36 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 22:27:36 volumio volumio[836]: error: Error browsingaudio_cast_folder/error_message:Error: Did not get expected response from server:{"Envelope":{"$":{"s:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/","xmlns:s":"http://schemas.xmlsoap.org/soap/envelope/"},"Body":[{"Fault":[{"faultcode":[{"_":"s:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request: Not a valid folder"}]}]}]}]}]}} Mar 17 22:27:36 volumio volumio[836]: error: Failed to execute browseSource: Mar 17 22:27:36 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:36 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33560. Mar 17 22:27:37 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:37 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:37 volumio go-librespot[19132]: Librespot-go daemon starting... Mar 17 22:27:37 volumio go-librespot[19132]: time="2025-03-17T22:27:37+01:00" level=info msg="generated new device id: 479ef2920c5a5d3d5d1a62c5b73d59a6e5c0c635" Mar 17 22:27:37 volumio go-librespot[19132]: time="2025-03-17T22:27:37+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+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]" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+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]" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+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]" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+01:00" level=debug msg="zeroconf server listening on port 45843" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+01:00" level=debug msg="obtained new client token: AAB3gEeV4QXAv87lTpu05oG6fHPisFpvtQJCKC5EPHw/jD1LzGXa+lqkaqwj3PCyaWogL0hR6L0u8aWKhja47F2YcgcQKnC/t1XnA5xGhov+DgDH2BEDGQ45F5miAgHK88MZiIXemdGaxVwYQJD9yEgEoSCEhGTg5akcrOwWvTQLsdY8jrH5KoqolKtRJfROFUUmJ+UCUAX+wSeCh96jjlcNAhOKkbvT8a8lPGhZ+rsFlAKd0fvDSTzVgdfI" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+01:00" level=debug msg="completed challenge" Mar 17 22:27:38 volumio go-librespot[19132]: time="2025-03-17T22:27:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:39 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:39 volumio volumio[836]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 17 22:27:40 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 22:27:40 volumio volumio[836]: info: Preload queue cleared Mar 17 22:27:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 17 22:27:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33561. Mar 17 22:27:41 volumio systemd[1]: Stopped go-librespot Daemon. Mar 17 22:27:42 volumio systemd[1]: Started go-librespot Daemon. Mar 17 22:27:42 volumio go-librespot[19141]: Librespot-go daemon starting... Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=info msg="generated new device id: e0e7db3edc10fa58136a108620810e9b670c3fe0" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=debug msg="stored credentials found for fat_lizzy" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+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]" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+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]" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+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]" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=debug msg="zeroconf server listening on port 36163" Mar 17 22:27:42 volumio volumio[836]: info: Initializing connection to go-librespot Websocket Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=debug msg="new websocket client" Mar 17 22:27:42 volumio volumio[836]: info: Connection to go-librespot Websocket established Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=debug msg="obtained new client token: AAB2uDSY8zzIjFIhi/Njdbsl73HR9u4AtH8FXElXDFnaZie2StEoZQCNqaFKiwh1QjFRuXGiJ8EzzFTmWKGf8qgLPXY8Q6y9v1/YU89fW//O9TLBw7VrayonbP5IzoVHUl0yUXQ/mJZktU+yIIpuUoe+vPzAqaKtZSlWg7cYJTFyrvwJi2Hwk0M5rDv6ITpyuo4WidC2ef1XcnGlCsIvgisBk2GwZq/BALAovvP7zzcQ7nk4SvnOptwefWl6KTI=" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=debug msg="completed keyexchange" Mar 17 22:27:42 volumio go-librespot[19141]: time="2025-03-17T22:27:42+01:00" level=debug msg="completed challenge" Mar 17 22:27:43 volumio go-librespot[19141]: time="2025-03-17T22:27:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 17 22:27:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 17 22:27:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 17 22:27:43 volumio volumio[836]: info: Connection to go-librespot Websocket closed Mar 17 22:27:44 volumio volumio[836]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 17 22:27:44 volumio volumio[836]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 17 22:27:44 volumio volumio[836]: TypeError: Cannot read property 'length' of undefined Mar 17 22:27:44 volumio volumio[836]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Mar 17 22:27:44 volumio volumio[836]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Mar 17 22:27:44 volumio volumio[836]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Mar 17 22:27:44 volumio volumio[836]: at Parser.emit (events.js:315:20) Mar 17 22:27:44 volumio volumio[836]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Mar 17 22:27:44 volumio volumio[836]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Mar 17 22:27:44 volumio volumio[836]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Mar 17 22:27:44 volumio volumio[836]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Mar 17 22:27:44 volumio volumio[836]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Mar 17 22:27:44 volumio volumio[836]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Mar 17 22:27:44 volumio volumio[836]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Mar 17 22:27:44 volumio volumio[836]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Mar 17 22:27:44 volumio volumio[836]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Mar 17 22:27:44 volumio volumio[836]: at IncomingMessage.emit (events.js:327:22) Mar 17 22:27:44 volumio volumio[836]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 17 22:27:44 volumio volumio[836]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 17 22:27:44 volumio volumio[836]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 17 22:27:45 volumio sudo[19172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-17 22:26 Mar 17 22:27:45 volumio sudo[19172]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"