-- Logs begin at Thu 2019-02-14 18:12:00 CST, end at Sun 2025-12-14 19:57:59 CST. -- Dec 14 19:56:00 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:56:00 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:00 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:56:00 volumio volumio[943]: (node:943) 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: 18) Dec 14 19:56:00 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:56:00 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:56:00 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:56:00 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:56:02 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:02 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:02 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:56:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 14 19:56:02 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:56:02 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:56:02 volumio go-librespot[2091]: Librespot-go daemon starting... Dec 14 19:56:02 volumio go-librespot[2091]: time="2025-12-14T19:56:02+08:00" level=info msg="generated new device id: b8b25658ed0e39104b4ad790715f908cd652ca3a" Dec 14 19:56:02 volumio go-librespot[2091]: time="2025-12-14T19:56:02+08:00" level=debug msg="stored credentials not found" Dec 14 19:56:04 volumio go-librespot[2091]: time="2025-12-14T19:56:04+08:00" level=debug msg="obtained new client token: AADkc+POqHpOq7fYBQI/2hVtYRALgK6ACmP03ILgBISgQJ7aG/i2YjJ1X2DEsLc9vGzuLxATJ8A0zdxF8iItmJtcKvDtWRd1sn1ZzM35cSENXZYhpx12v3lA4DzSUJ+wFk5p9fOzzcnFg+KfG2HtNgbicJS7Zaq4GWrpJrFpORxyWMqnFtCaM4y2ETD2zZ+4pd5smSG+U7YG5ulzdBGKEVJgUF1jv4t/vIGxjfW9pyWjad9kHY/MYSICcD9IGHk22g==" Dec 14 19:56:05 volumio go-librespot[2091]: time="2025-12-14T19:56:05+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 14 19:56:05 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:05 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:56:05 volumio go-librespot[2091]: time="2025-12-14T19:56:05+08:00" level=debug msg="new websocket client" Dec 14 19:56:05 volumio go-librespot[2091]: time="2025-12-14T19:56:05+08:00" level=debug msg="completed keyexchange" Dec 14 19:56:06 volumio go-librespot[2091]: time="2025-12-14T19:56:06+08:00" level=debug msg="completed challenge" Dec 14 19:56:06 volumio go-librespot[2091]: time="2025-12-14T19:56:06+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:56:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:56:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:56:06 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:56:08 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:08 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:56:08 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:08 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:56:08 volumio volumio[943]: (node:943) 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: 19) Dec 14 19:56:08 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:56:08 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:56:08 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:56:08 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:56:09 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:09 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:56:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 14 19:56:09 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:56:09 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:56:09 volumio go-librespot[2102]: Librespot-go daemon starting... Dec 14 19:56:09 volumio go-librespot[2102]: time="2025-12-14T19:56:09+08:00" level=info msg="generated new device id: b3255e4d960fbc87e12e3af1bfcac8621756f722" Dec 14 19:56:09 volumio go-librespot[2102]: time="2025-12-14T19:56:09+08:00" level=debug msg="stored credentials not found" Dec 14 19:56:11 volumio go-librespot[2102]: time="2025-12-14T19:56:11+08:00" level=debug msg="obtained new client token: AACmngsX3Vvft0+ERNCKGMs99GmbhHpiKDDhwrZ/04YQNGczZXr/ThFhdDQIZdshc/owdXam4yZ4UKuGU9ooqtB4jgtiCnZwtrQKJm5V/+Rb1OVczL/B0y7a5S+GgYc/rX84Jp3dJxJDa/GbOqh4VGTxe5k1UFVvbpFNvkcu4t7iKrFl3lRAPnmYGnaXvFu2XCXAIz/ig3IsMHx60puIAUsgFcy3Sj4ldjMM19IjGU/hMXTJcolI521d1ye+fCvoJw==" Dec 14 19:56:12 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:12 volumio go-librespot[2102]: time="2025-12-14T19:56:12+08:00" level=debug msg="new websocket client" Dec 14 19:56:12 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:56:12 volumio go-librespot[2102]: time="2025-12-14T19:56:12+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:56:14 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:15 volumio go-librespot[2102]: time="2025-12-14T19:56:15+08:00" level=debug msg="completed keyexchange" Dec 14 19:56:15 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:56:15 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:56:15 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:56:15 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:56:15 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:56:15 volumio go-librespot[2102]: time="2025-12-14T19:56:15+08:00" level=debug msg="completed challenge" Dec 14 19:56:16 volumio go-librespot[2102]: time="2025-12-14T19:56:16+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:56:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:56:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:56:16 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: socket hang up Dec 14 19:56:16 volumio volumio[943]: at connResetException (internal/errors.js:607:14) Dec 14 19:56:16 volumio volumio[943]: at Socket.socketOnEnd (_http_client.js:493:23) Dec 14 19:56:16 volumio volumio[943]: at Socket.emit (events.js:327:22) Dec 14 19:56:16 volumio volumio[943]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 14 19:56:16 volumio volumio[943]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 14 19:56:16 volumio volumio[943]: (node:943) 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: 20) Dec 14 19:56:16 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:56:19 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:19 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:56:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 14 19:56:19 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:56:19 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:56:19 volumio go-librespot[2111]: Librespot-go daemon starting... Dec 14 19:56:19 volumio go-librespot[2111]: time="2025-12-14T19:56:19+08:00" level=info msg="generated new device id: 3304b7f96e6e7b9dbbb27730a9477e5ea7afc4e6" Dec 14 19:56:19 volumio go-librespot[2111]: time="2025-12-14T19:56:19+08:00" level=debug msg="stored credentials not found" Dec 14 19:56:20 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:20 volumio go-librespot[2111]: time="2025-12-14T19:56:20+08:00" level=debug msg="obtained new client token: AADjpI5k3M3iBToQDNenAh+rCQzopIjU4QsWKtnmFPKY881RtKmoiVxlrYbuw58bADHaCnwc4XjqUsPB29r+08x4RF6mh1zUS/8O5B4W/kOvamD1+RLXAkh3mlZ4u3jvPV2N1nayO97ZqOrHmdnZcDQRB7ckWDlFRryrI/d+ghbjOhaAbURUNzqcpBJeSl00WpXIqXhdWP7OwlLnERhcaOaMijdlsnEB5eEqR6i6/SMNytVbZYjWe8BSF24ftMP6FA==" Dec 14 19:56:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 14 19:56:22 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:22 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:56:22 volumio go-librespot[2111]: time="2025-12-14T19:56:22+08:00" level=debug msg="new websocket client" Dec 14 19:56:22 volumio go-librespot[2111]: time="2025-12-14T19:56:22+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:56:24 volumio go-librespot[2111]: time="2025-12-14T19:56:24+08:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Dec 14 19:56:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:56:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:56:24 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:56:25 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:56:25 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:25 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:56:25 volumio volumio[943]: (node:943) 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: 21) Dec 14 19:56:25 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:56:25 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:56:25 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:56:25 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:56:26 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:27 volumio kernel: hwmon hwmon1: Voltage normalised Dec 14 19:56:27 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:27 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:56:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Dec 14 19:56:27 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:56:27 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:56:27 volumio go-librespot[2162]: Librespot-go daemon starting... Dec 14 19:56:27 volumio go-librespot[2162]: time="2025-12-14T19:56:27+08:00" level=info msg="generated new device id: e8898c25b4cbd7006f31552de1e9e50a58dcd1e4" Dec 14 19:56:27 volumio go-librespot[2162]: time="2025-12-14T19:56:27+08:00" level=debug msg="stored credentials not found" Dec 14 19:56:28 volumio go-librespot[2162]: time="2025-12-14T19:56:28+08:00" level=debug msg="obtained new client token: AACvWxEGFLPWPuuVwC4b6JBesffiCWQsQO12C+Ato69sO3zMWBBO9RfRPBUf3ynaC2h98XkKPEJOJoxioeXLxR/qKamEI1J4ia0R5m7jslu0SckpPykkrmrqh/tvIKyBirkcWB0+7QV3nOxTz1zYblE/WUqFIKCpebw0dGB2B9NOfzB2GSvg/IXL8F/g9J5iTHGIm8tS+Pgf6DmAzih6OiNV2Dz00/tBd/WbrahyWqKZBRDBfiS73Jr1bt8RZ4z1AQ==" Dec 14 19:56:29 volumio go-librespot[2162]: time="2025-12-14T19:56:29+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 14 19:56:30 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:30 volumio go-librespot[2162]: time="2025-12-14T19:56:30+08:00" level=debug msg="new websocket client" Dec 14 19:56:30 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:56:32 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:32 volumio go-librespot[2162]: time="2025-12-14T19:56:32+08:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Dec 14 19:56:32 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:56:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:56:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:56:33 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 14 19:56:33 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:56:33 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:33 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:56:33 volumio volumio[943]: (node:943) 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: 22) Dec 14 19:56:33 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:56:33 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:56:33 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:56:33 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:56:35 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:35 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:56:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 14 19:56:35 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:56:35 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:56:35 volumio go-librespot[2172]: Librespot-go daemon starting... Dec 14 19:56:35 volumio go-librespot[2172]: time="2025-12-14T19:56:35+08:00" level=info msg="generated new device id: 4882e4200fc1b30957c8894bfee78b5c81bf10ff" Dec 14 19:56:35 volumio go-librespot[2172]: time="2025-12-14T19:56:35+08:00" level=debug msg="stored credentials not found" Dec 14 19:56:36 volumio go-librespot[2172]: time="2025-12-14T19:56:36+08:00" level=debug msg="obtained new client token: AAByOacldzx7+kaEhd3zvR+onv/ODnjBWvzs70DiLtRw4F7ORD7+Kr7ve5kru96g+L8y4HAZvc0vEMcjoCJUzvF3pagwKo+Oi1rV3q+nzUXpM6VRDTovNa5lumlal+ZlfIn7AQmGrCEEM/MLUEEsTHm+ACIFnes4wvAdLf5gFgkiXnNKMN5u2TFRdJm0eFzE2JQgkClQ0ANRssLQi+eqFbnnG1LPS7V9rIQzNT+lLPQMtOIEINFv3+2xohn3YZBUWQ==" Dec 14 19:56:37 volumio kernel: hwmon hwmon1: Voltage normalised Dec 14 19:56:37 volumio go-librespot[2172]: time="2025-12-14T19:56:37+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:56:37 volumio volumio[943]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","DEVLINKS":"/dev/disk/by-id/usb-USB_SanDisk_3.2Gen1_010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1-0:0-part1 /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1:1.0-scsi-0:0:0:0-part1","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"26","ID_BUS":"usb","ID_INSTANCE":"0:0","ID_MODEL":"SanDisk_3.2Gen1","ID_MODEL_ENC":"\\x20SanDisk\\x203.2Gen1","ID_MODEL_ID":"5591","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_1_0-scsi-0_0_0_0","ID_REVISION":"1.00","ID_SERIAL":"USB_SanDisk_3.2Gen1_010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1-0:0","ID_SERIAL_SHORT":"010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"USB","ID_VENDOR_ENC":"\\x20USB\\x20\\x20\\x20\\x20","ID_VENDOR_ID":"0781","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"1845","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"15686597"} Dec 14 19:56:37 volumio kernel: usb 2-1: USB disconnect, device number 2 Dec 14 19:56:37 volumio volumio[943]: error: Cannot associate FS Label, not mounting Dec 14 19:56:38 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:38 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:38 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:56:38 volumio go-librespot[2172]: time="2025-12-14T19:56:38+08:00" level=debug msg="new websocket client" Dec 14 19:56:40 volumio go-librespot[2172]: time="2025-12-14T19:56:40+08:00" level=debug msg="completed keyexchange" Dec 14 19:56:40 volumio go-librespot[2172]: time="2025-12-14T19:56:40+08:00" level=debug msg="completed challenge" Dec 14 19:56:40 volumio kernel: usb 2-1: new SuperSpeed USB device number 3 using xhci_hcd Dec 14 19:56:40 volumio kernel: usb 2-1: New USB device found, idVendor=0781, idProduct=5591, bcdDevice= 1.00 Dec 14 19:56:40 volumio kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Dec 14 19:56:40 volumio kernel: usb 2-1: Product: SanDisk 3.2Gen1 Dec 14 19:56:40 volumio kernel: usb 2-1: Manufacturer: USB Dec 14 19:56:40 volumio kernel: usb 2-1: SerialNumber: 010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1 Dec 14 19:56:40 volumio kernel: usb-storage 2-1:1.0: USB Mass Storage device detected Dec 14 19:56:40 volumio kernel: scsi host0: usb-storage 2-1:1.0 Dec 14 19:56:40 volumio go-librespot[2172]: time="2025-12-14T19:56:40+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:56:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:56:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:56:40 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:56:41 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:56:41 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:41 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:56:41 volumio volumio[943]: (node:943) 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: 23) Dec 14 19:56:41 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:56:41 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:56:41 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:56:41 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:56:41 volumio kernel: scsi 0:0:0:0: Direct-Access USB SanDisk 3.2Gen1 1.00 PQ: 0 ANSI: 6 Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] 240328704 512-byte logical blocks: (123 GB/115 GiB) Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] Write Protect is off Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA Dec 14 19:56:41 volumio kernel: sda: sda1 Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f8 00 00 01 00 Dec 14 19:56:41 volumio kernel: critical medium error, dev sda, sector 240328696 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 00 88 00 00 78 00 Dec 14 19:56:41 volumio kernel: critical medium error, dev sda, sector 136 op 0x0:(READ) flags 0x80700 phys_seg 15 prio class 2 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 08 00 00 f8 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 264 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 2 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 48 00 00 08 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 328 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:56:42 volumio kernel: Buffer I/O error on dev sda, logical block 41, async page read Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 f8 00 00 08 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 504 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:56:42 volumio kernel: Buffer I/O error on dev sda, logical block 63, async page read Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 00 a0 00 00 08 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 160 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 00 a8 00 00 78 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 168 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 28 00 00 f8 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 296 op 0x0:(READ) flags 0x80700 phys_seg 10 prio class 2 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 00 b0 00 00 08 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 176 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:56:42 volumio kernel: Buffer I/O error on dev sda1, logical block 18, async page read Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:56:42 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 48 00 00 08 00 Dec 14 19:56:42 volumio kernel: critical medium error, dev sda, sector 328 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:56:42 volumio kernel: Buffer I/O error on dev sda1, logical block 37, async page read Dec 14 19:56:42 volumio volumio[943]: info: Mounting Device 288016118015E65A Dec 14 19:56:42 volumio sudo[2192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/288016118015E65A -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Dec 14 19:56:42 volumio sudo[2192]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 19:56:42 volumio kernel: Buffer I/O error on dev sda1, logical block 30041083, async page read Dec 14 19:56:42 volumio kernel: ext3: Unknown parameter 'dmask' Dec 14 19:56:42 volumio kernel: ext2: Unknown parameter 'dmask' Dec 14 19:56:42 volumio kernel: ext4: Unknown parameter 'dmask' Dec 14 19:56:42 volumio kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Dec 14 19:56:42 volumio sudo[2192]: pam_unix(sudo:session): session closed for user root Dec 14 19:56:42 volumio kernel: F2FS-fs (sda1): Magic Mismatch, valid(0xf2f52010) - read(0x8e0e8966) Dec 14 19:56:42 volumio kernel: F2FS-fs (sda1): Can't find valid F2FS filesystem in 1th superblock Dec 14 19:56:42 volumio kernel: F2FS-fs (sda1): Magic Mismatch, valid(0xf2f52010) - read(0x0) Dec 14 19:56:42 volumio kernel: F2FS-fs (sda1): Can't find valid F2FS filesystem in 2th superblock Dec 14 19:56:42 volumio kernel: squashfs: Unknown parameter 'dmask' Dec 14 19:56:42 volumio volumio[943]: mount: /media/288016118015E65A: wrong fs type, bad option, bad superblock on /dev/sda1, missing codepage or helper program, or other error. Dec 14 19:56:42 volumio volumio[943]: error: Failed to mount 288016118015E65A: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/288016118015E65A" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Dec 14 19:56:42 volumio volumio[943]: mount: /media/288016118015E65A: wrong fs type, bad option, bad superblock on /dev/sda1, missing codepage or helper program, or other error. Dec 14 19:56:43 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:43 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:43 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 14 19:56:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:56:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 14 19:56:43 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:56:43 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:56:43 volumio go-librespot[2194]: Librespot-go daemon starting... Dec 14 19:56:44 volumio go-librespot[2194]: time="2025-12-14T19:56:44+08:00" level=info msg="generated new device id: a538a78ae63adce22d2f4f3b40ebf248699cdeae" Dec 14 19:56:44 volumio go-librespot[2194]: time="2025-12-14T19:56:44+08:00" level=debug msg="stored credentials not found" Dec 14 19:56:44 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:45 volumio go-librespot[2194]: time="2025-12-14T19:56:45+08:00" level=debug msg="obtained new client token: AAAteA+pVYIBW/JFK+1JZkoWU0ihf0pxF5IBRhm0bpumyurIOzhcR2wqFOMiuNozY+iL9nGfyoQwYkAnlwHdMyh8hIvR57ViXZX8Vqx2Bgu7hB/xjtNP5uAkaag/tIJzvIEG1g1q0bYVwmcPLalPf75tNycvZc8r6pI4rAzmDFtByxb/HAdBWjcaGJlatA72uHevOrlXXlz26pj4dUPljEcOuGN5CJRCWoWhIjKZ3S5rquLf8WBepPPhDiqW+kNrnQ==" Dec 14 19:56:46 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:46 volumio go-librespot[2194]: time="2025-12-14T19:56:46+08:00" level=debug msg="new websocket client" Dec 14 19:56:46 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:56:48 volumio go-librespot[2194]: time="2025-12-14T19:56:48+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:56:49 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:56:49 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:56:49 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:56:49 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:56:49 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:56:50 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:51 volumio go-librespot[2194]: time="2025-12-14T19:56:51+08:00" level=debug msg="completed keyexchange" Dec 14 19:56:51 volumio go-librespot[2194]: time="2025-12-14T19:56:51+08:00" level=debug msg="completed challenge" Dec 14 19:56:51 volumio go-librespot[2194]: time="2025-12-14T19:56:51+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:56:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:56:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:56:51 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: socket hang up Dec 14 19:56:51 volumio volumio[943]: at connResetException (internal/errors.js:607:14) Dec 14 19:56:51 volumio volumio[943]: at Socket.socketOnEnd (_http_client.js:493:23) Dec 14 19:56:51 volumio volumio[943]: at Socket.emit (events.js:327:22) Dec 14 19:56:51 volumio volumio[943]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 14 19:56:51 volumio volumio[943]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 14 19:56:51 volumio volumio[943]: (node:943) 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: 24) Dec 14 19:56:51 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:56:54 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:54 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:56:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:56:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Dec 14 19:56:54 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:56:54 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:56:54 volumio go-librespot[2202]: Librespot-go daemon starting... Dec 14 19:56:54 volumio go-librespot[2202]: time="2025-12-14T19:56:54+08:00" level=info msg="generated new device id: 4615e65c3b69616899a618844cd25bd0d431e2e8" Dec 14 19:56:54 volumio go-librespot[2202]: time="2025-12-14T19:56:54+08:00" level=debug msg="stored credentials not found" Dec 14 19:56:55 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:56:56 volumio go-librespot[2202]: time="2025-12-14T19:56:56+08:00" level=debug msg="obtained new client token: AACuGJvuTgDZndtmS1gqJVeYHjrhijAFCkFaA8ZJPOnClAVUSrqWn+f9XTLi1FytXnXgUek86Z1ihBCuJazrPtiAjaWKnpOnAWKLD3LSlmqMmhtXDDLDcz+dCOOoX7v4S/TuQfvH2haIrycgldVp/FSg/52Y4txMMCiWqb2RwPTKZsDD3gY3MrhrBNPt0jLJs6BhJ4fdnzZXJxH0bnjTArPY4+2URCak+AOQpJx2BFpbaUrJhMJ4aoA7qESijr1tiw==" Dec 14 19:56:57 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:56:57 volumio go-librespot[2202]: time="2025-12-14T19:56:57+08:00" level=debug msg="new websocket client" Dec 14 19:56:57 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:56:58 volumio go-librespot[2202]: time="2025-12-14T19:56:58+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:56:58 volumio go-librespot[2202]: time="2025-12-14T19:56:58+08:00" level=debug msg="completed keyexchange" Dec 14 19:56:59 volumio go-librespot[2202]: time="2025-12-14T19:56:59+08:00" level=debug msg="completed challenge" Dec 14 19:56:59 volumio go-librespot[2202]: time="2025-12-14T19:56:59+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:56:59 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:56:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:56:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:57:00 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:57:00 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:00 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:57:00 volumio volumio[943]: (node:943) 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: 25) Dec 14 19:57:00 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 14 19:57:00 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:00 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:00 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:57:01 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:02 volumio kernel: hwmon hwmon1: Voltage normalised Dec 14 19:57:02 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:02 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:02 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:02 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:57:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Dec 14 19:57:02 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:57:02 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:57:02 volumio go-librespot[2216]: Librespot-go daemon starting... Dec 14 19:57:02 volumio go-librespot[2216]: time="2025-12-14T19:57:02+08:00" level=info msg="generated new device id: aeeb89e405aeeeae0ca8262e0016d58908358dcc" Dec 14 19:57:02 volumio go-librespot[2216]: time="2025-12-14T19:57:02+08:00" level=debug msg="stored credentials not found" Dec 14 19:57:02 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:02 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:03 volumio sudo[2224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 14 19:57:03 volumio sudo[2224]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 19:57:03 volumio sudo[2224]: pam_unix(sudo:session): session closed for user root Dec 14 19:57:03 volumio sudo[2227]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 14 19:57:03 volumio sudo[2227]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 19:57:03 volumio sudo[2227]: pam_unix(sudo:session): session closed for user root Dec 14 19:57:03 volumio volumio[943]: verbose: New Socket.io Connection to 192.168.101.4 from 192.168.101.3 UA: Mozilla/5.0 (Linux; Android 15; SM-S9010 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Total Clients: 8 Dec 14 19:57:04 volumio sudo[2230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 14 19:57:04 volumio sudo[2230]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 19:57:04 volumio sudo[2230]: pam_unix(sudo:session): session closed for user root Dec 14 19:57:04 volumio sudo[2233]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 14 19:57:04 volumio sudo[2233]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 19:57:04 volumio sudo[2233]: pam_unix(sudo:session): session closed for user root Dec 14 19:57:04 volumio volumio[943]: verbose: New Socket.io Connection to 192.168.101.4 from 192.168.101.3 UA: Mozilla/5.0 (Linux; Android 15; SM-S9010 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Total Clients: 9 Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::volumioGetVisibleSources Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:04 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::volumioGetQueue Dec 14 19:57:04 volumio volumio[943]: info: CoreStateMachine::getQueue Dec 14 19:57:04 volumio volumio[943]: info: CorePlayQueue::getQueue Dec 14 19:57:04 volumio volumio[943]: info: Listing playlists Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 14 19:57:04 volumio volumio[943]: info: Received Get System Info Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 14 19:57:04 volumio volumio[943]: info: Discovery: Getting this device information Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:04 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:04 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 14 19:57:04 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 14 19:57:05 volumio go-librespot[2216]: time="2025-12-14T19:57:05+08:00" level=debug msg="obtained new client token: AAB76Jr/gzzmpbmLLvICJ6cSraIqUDIGK7TZv+dzAQe47g+ZZYjmkuBYxJujY585Gq2ei7l+ddxUYxJIZDYPcB3aW6RVabR3uR+yzfd9rnFUaoQMKBVqeHeOist20+EyWR+tj0H4bZLfUb7LWA5bXUdcw8HHDiwmNAs8AFV7nMqNiC8sLNTnPEZOTUh3Ugfad4DCxntTSYsL+kvWQusZfXdxAXjpfwZR7NlnxYdh3Is/uFySMUf8Sw8Dw5ae2xOLTA==" Dec 14 19:57:05 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:05 volumio go-librespot[2216]: time="2025-12-14T19:57:05+08:00" level=debug msg="new websocket client" Dec 14 19:57:05 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:57:06 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 14 19:57:06 volumio volumio[943]: info: Received Get System Info Dec 14 19:57:06 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 14 19:57:06 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 14 19:57:06 volumio volumio[943]: info: Discovery: Getting this device information Dec 14 19:57:06 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:06 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:06 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 14 19:57:06 volumio go-librespot[2216]: time="2025-12-14T19:57:06+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 14 19:57:06 volumio go-librespot[2216]: time="2025-12-14T19:57:06+08:00" level=debug msg="completed keyexchange" Dec 14 19:57:07 volumio go-librespot[2216]: time="2025-12-14T19:57:07+08:00" level=debug msg="completed challenge" Dec 14 19:57:07 volumio go-librespot[2216]: time="2025-12-14T19:57:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:57:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:57:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:57:07 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:57:07 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:08 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:57:08 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:08 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:57:08 volumio volumio[943]: (node:943) 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: 26) Dec 14 19:57:08 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Dec 14 19:57:08 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:08 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:08 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:57:09 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:09 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:10 volumio kernel: usb 2-1: USB disconnect, device number 3 Dec 14 19:57:10 volumio volumio[943]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","DEVLINKS":"/dev/disk/by-id/usb-USB_SanDisk_3.2Gen1_010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1-0:0-part1 /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1:1.0-scsi-0:0:0:0-part1 /dev/disk/by-partuuid/be90ae9a-01 /dev/disk/by-uuid/288016118015E65A","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"28","ID_BUS":"usb","ID_FS_TYPE":"ntfs","ID_FS_USAGE":"filesystem","ID_FS_UUID":"288016118015E65A","ID_FS_UUID_ENC":"288016118015E65A","ID_INSTANCE":"0:0","ID_MODEL":"SanDisk_3.2Gen1","ID_MODEL_ENC":"\\x20SanDisk\\x203.2Gen1","ID_MODEL_ID":"5591","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"32","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"240328672","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"be90ae9a-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"be90ae9a","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_1_0-scsi-0_0_0_0","ID_REVISION":"1.00","ID_SERIAL":"USB_SanDisk_3.2Gen1_010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1-0:0","ID_SERIAL_SHORT":"010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"USB","ID_VENDOR_ENC":"\\x20USB\\x20\\x20\\x20\\x20","ID_VENDOR_ID":"0781","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"1881","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"285334791"} Dec 14 19:57:10 volumio sudo[2241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sda1 Dec 14 19:57:10 volumio sudo[2241]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 19:57:10 volumio sudo[2241]: pam_unix(sudo:session): session closed for user root Dec 14 19:57:10 volumio volumio[943]: umount: /dev/sda1: no mount point specified. Dec 14 19:57:10 volumio volumio[943]: error: Failed to umount 288016118015E65A: Error: Command failed: /usr/bin/sudo /bin/umount -f "/dev/sda1" Dec 14 19:57:10 volumio volumio[943]: umount: /dev/sda1: no mount point specified. Dec 14 19:57:10 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:10 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:57:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Dec 14 19:57:10 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:57:10 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:57:10 volumio go-librespot[2243]: Librespot-go daemon starting... Dec 14 19:57:10 volumio go-librespot[2243]: time="2025-12-14T19:57:10+08:00" level=info msg="generated new device id: f31c9f14e90444ccf1b8a4bd5e7464f265399b2c" Dec 14 19:57:10 volumio go-librespot[2243]: time="2025-12-14T19:57:10+08:00" level=debug msg="stored credentials not found" Dec 14 19:57:11 volumio go-librespot[2243]: time="2025-12-14T19:57:11+08:00" level=debug msg="obtained new client token: AAB72uY6DxL6jgxFEG5Mz9XOlfgFz4hrJ8zZ/kOUchAW4HeGjzTBATm3QfWb4PUKwDdTui5IEEuWPeEApF4QFxq03HSQ0wlvn+B6FEmFJ0tkEPTpmo1vxpp8Rbvi8YfKCzcrkO6Sw/5q1J3sxzXd7+sGFULSLSkiJh9QvjvYfW+b8CbozncRJTqatKiHeXZR15Kh/HH4KZEp2SDsERSg/dLH/Zw2B4GG44/eNpVNDI2lJSAY9am/r7WueQuPKyM62w==" Dec 14 19:57:13 volumio go-librespot[2243]: time="2025-12-14T19:57:13+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:57:13 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:13 volumio go-librespot[2243]: time="2025-12-14T19:57:13+08:00" level=debug msg="new websocket client" Dec 14 19:57:13 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:57:13 volumio go-librespot[2243]: time="2025-12-14T19:57:13+08:00" level=debug msg="completed keyexchange" Dec 14 19:57:13 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:14 volumio go-librespot[2243]: time="2025-12-14T19:57:14+08:00" level=debug msg="completed challenge" Dec 14 19:57:14 volumio go-librespot[2243]: time="2025-12-14T19:57:14+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:57:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:57:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:57:14 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:57:16 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:57:16 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:16 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:57:16 volumio volumio[943]: (node:943) 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: 27) Dec 14 19:57:16 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Dec 14 19:57:16 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:16 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:16 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:57:17 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:17 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:57:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Dec 14 19:57:17 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:57:17 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:57:17 volumio go-librespot[2252]: Librespot-go daemon starting... Dec 14 19:57:17 volumio go-librespot[2252]: time="2025-12-14T19:57:17+08:00" level=info msg="generated new device id: e8244f724c27097656ca8281e13f06621fb215e5" Dec 14 19:57:17 volumio go-librespot[2252]: time="2025-12-14T19:57:17+08:00" level=debug msg="stored credentials not found" Dec 14 19:57:19 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:19 volumio go-librespot[2252]: time="2025-12-14T19:57:19+08:00" level=debug msg="obtained new client token: AADxN4EN6ZEOyOf3p8FBsEeYvTwhUxU0zTJHmInUO6Gj3eyVk4L+hU3LwSEZ0rxRUTPX8e5suPN0hkpsZijp/SUL/wOxR2H8UphVzZGsTbXOOtu9or1xGvCR6htNvXo6HWIdebJvNmaJZ3+Bl8TcmeEtY8ylbOdMuSxctuZQ7Xo6zVvvVVU5jhsufMoVSPUjV6oI5mX3IDqKPLYeyW08waQPtt49DeD+ZnGpj120dC0+o1pMG/JE7FcBcC8oPZuCPA==" Dec 14 19:57:20 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:20 volumio go-librespot[2252]: time="2025-12-14T19:57:20+08:00" level=debug msg="new websocket client" Dec 14 19:57:20 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:57:21 volumio go-librespot[2252]: time="2025-12-14T19:57:21+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 14 19:57:23 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:57:23 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Dec 14 19:57:23 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:23 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:23 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:57:23 volumio kernel: usb 1-1.3: new high-speed USB device number 4 using xhci_hcd Dec 14 19:57:23 volumio go-librespot[2252]: time="2025-12-14T19:57:23+08:00" level=debug msg="completed keyexchange" Dec 14 19:57:23 volumio kernel: usb 1-1.3: New USB device found, idVendor=0781, idProduct=5591, bcdDevice= 1.00 Dec 14 19:57:23 volumio kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Dec 14 19:57:23 volumio kernel: usb 1-1.3: Product: SanDisk 3.2Gen1 Dec 14 19:57:23 volumio kernel: usb 1-1.3: Manufacturer: USB Dec 14 19:57:23 volumio kernel: usb 1-1.3: SerialNumber: 010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1 Dec 14 19:57:23 volumio kernel: usb-storage 1-1.3:1.0: USB Mass Storage device detected Dec 14 19:57:23 volumio kernel: scsi host0: usb-storage 1-1.3:1.0 Dec 14 19:57:24 volumio go-librespot[2252]: time="2025-12-14T19:57:24+08:00" level=debug msg="completed challenge" Dec 14 19:57:24 volumio go-librespot[2252]: time="2025-12-14T19:57:24+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:57:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:57:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:57:24 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: socket hang up Dec 14 19:57:24 volumio volumio[943]: at connResetException (internal/errors.js:607:14) Dec 14 19:57:24 volumio volumio[943]: at Socket.socketOnEnd (_http_client.js:493:23) Dec 14 19:57:24 volumio volumio[943]: at Socket.emit (events.js:327:22) Dec 14 19:57:24 volumio volumio[943]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 14 19:57:24 volumio volumio[943]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 14 19:57:24 volumio volumio[943]: (node:943) 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: 28) Dec 14 19:57:24 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:57:24 volumio kernel: scsi 0:0:0:0: Direct-Access USB SanDisk 3.2Gen1 1.00 PQ: 0 ANSI: 6 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] 240328704 512-byte logical blocks: (123 GB/115 GiB) Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] Write Protect is off Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA Dec 14 19:57:24 volumio kernel: sda: sda1 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk Dec 14 19:57:24 volumio kernel: scsi_io_completion_action: 2 callbacks suppressed Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f8 00 00 01 00 Dec 14 19:57:24 volumio kernel: blk_print_req_error: 2 callbacks suppressed Dec 14 19:57:24 volumio kernel: critical medium error, dev sda, sector 240328696 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f9 00 00 01 00 Dec 14 19:57:24 volumio kernel: critical medium error, dev sda, sector 240328697 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:57:24 volumio kernel: Buffer I/O error on dev sda, logical block 30041087, async page read Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f8 00 00 01 00 Dec 14 19:57:24 volumio kernel: critical medium error, dev sda, sector 240328696 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Dec 14 19:57:24 volumio volumio[943]: error: Cannot associate FS Label, not mounting Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:24 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f9 00 00 01 00 Dec 14 19:57:24 volumio kernel: critical medium error, dev sda, sector 240328697 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:57:24 volumio kernel: Buffer I/O error on dev sda1, logical block 30041083, async page read Dec 14 19:57:25 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:27 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:27 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:57:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Dec 14 19:57:27 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:57:27 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:57:27 volumio go-librespot[2309]: Librespot-go daemon starting... Dec 14 19:57:27 volumio go-librespot[2309]: time="2025-12-14T19:57:27+08:00" level=info msg="generated new device id: ae27e6d51593ef5641a9ebb14b7c3ccc907b3c8b" Dec 14 19:57:27 volumio go-librespot[2309]: time="2025-12-14T19:57:27+08:00" level=debug msg="stored credentials not found" Dec 14 19:57:28 volumio go-librespot[2309]: time="2025-12-14T19:57:28+08:00" level=debug msg="obtained new client token: AACGU7QJ8ducLW4zqb6aJk+X1fxDyVYgQTDVFQSS23NgoXekss67ri82Z8hY09rxqs5EY8CZxQ8pRpb/rcstvX5yl56oQzo6qIkXEubdM6MJCuKHvhxz3BCBSGLBBryXbOekL8xuAGINpoJZQEDwRSuT5qaoL5gqxhwp5lW7akwFwC1vqudvolICJ6pqV7ph9UkbKqMu23gjCzGYtCCMPGCWDL8Eff6rNu/NjF+uMXsOWY9PHxO4l9bxQvRmFPLHaQ==" Dec 14 19:57:29 volumio go-librespot[2309]: time="2025-12-14T19:57:29+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:57:30 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:30 volumio go-librespot[2309]: time="2025-12-14T19:57:30+08:00" level=debug msg="new websocket client" Dec 14 19:57:30 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:57:31 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:32 volumio go-librespot[2309]: time="2025-12-14T19:57:32+08:00" level=debug msg="completed keyexchange" Dec 14 19:57:33 volumio go-librespot[2309]: time="2025-12-14T19:57:33+08:00" level=debug msg="completed challenge" Dec 14 19:57:33 volumio go-librespot[2309]: time="2025-12-14T19:57:33+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:57:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:57:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:57:33 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:57:33 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:57:33 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:33 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:57:33 volumio volumio[943]: (node:943) 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: 29) Dec 14 19:57:33 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Dec 14 19:57:33 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:33 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:33 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:57:36 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:36 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:36 volumio kernel: usb 1-1.3: USB disconnect, device number 4 Dec 14 19:57:36 volumio volumio[943]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","DEVLINKS":"/dev/disk/by-id/usb-USB_SanDisk_3.2Gen1_010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1-0:0-part1 /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.3:1.0-scsi-0:0:0:0-part1","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"29","ID_BUS":"usb","ID_INSTANCE":"0:0","ID_MODEL":"SanDisk_3.2Gen1","ID_MODEL_ENC":"\\x20SanDisk\\x203.2Gen1","ID_MODEL_ID":"5591","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.3:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_3_1_0-scsi-0_0_0_0","ID_REVISION":"1.00","ID_SERIAL":"USB_SanDisk_3.2Gen1_010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1-0:0","ID_SERIAL_SHORT":"010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"USB","ID_VENDOR_ENC":"\\x20USB\\x20\\x20\\x20\\x20","ID_VENDOR_ID":"0781","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"1915","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"327667761"} Dec 14 19:57:36 volumio volumio[943]: error: Cannot associate FS Label, not mounting Dec 14 19:57:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:57:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Dec 14 19:57:36 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:57:36 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:57:36 volumio go-librespot[2322]: Librespot-go daemon starting... Dec 14 19:57:36 volumio go-librespot[2322]: time="2025-12-14T19:57:36+08:00" level=info msg="generated new device id: 85ff9b2088a3f57d7df1e20fe866a6b95c09023b" Dec 14 19:57:36 volumio go-librespot[2322]: time="2025-12-14T19:57:36+08:00" level=debug msg="stored credentials not found" Dec 14 19:57:37 volumio go-librespot[2322]: time="2025-12-14T19:57:37+08:00" level=debug msg="obtained new client token: AADj3p2G+prex1SMTUIqgjdVxD3WqdjVFfzb3XdCwEiK2lB2VWAGlHE0eI84+9/Vwe+CLuc/G+IdzfuDgo2aoMCwlbzkxyy9rLNzK5JHtmX6R7mMEiwnr9I8fb93xug7vwXN3YJV6rAydE52zKN7T4w5dDFz4t9KxgxCdd+peNcre5jdVIPxlwe1Nttkp70ccHVtmk+wvo9ZKZmQW0GjSgS9BSXtOCUekHArbomf1asFldl3s2WvnlKd+RteaYY=" Dec 14 19:57:37 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:38 volumio kernel: usb 2-1: new SuperSpeed USB device number 4 using xhci_hcd Dec 14 19:57:38 volumio kernel: usb 2-1: New USB device found, idVendor=0781, idProduct=5591, bcdDevice= 1.00 Dec 14 19:57:38 volumio kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Dec 14 19:57:38 volumio kernel: usb 2-1: Product: SanDisk 3.2Gen1 Dec 14 19:57:38 volumio kernel: usb 2-1: Manufacturer: USB Dec 14 19:57:38 volumio kernel: usb 2-1: SerialNumber: 010119094c7551071594a7780ce8fbb8a1567d5e4af944f916af92ef3df693a1d31f000000000000000000002aaba6e8ff130c0091558107832eddb1 Dec 14 19:57:38 volumio kernel: usb-storage 2-1:1.0: USB Mass Storage device detected Dec 14 19:57:38 volumio kernel: scsi host0: usb-storage 2-1:1.0 Dec 14 19:57:39 volumio go-librespot[2322]: time="2025-12-14T19:57:39+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 14 19:57:39 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:39 volumio go-librespot[2322]: time="2025-12-14T19:57:39+08:00" level=debug msg="new websocket client" Dec 14 19:57:39 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:57:39 volumio kernel: scsi 0:0:0:0: Direct-Access USB SanDisk 3.2Gen1 1.00 PQ: 0 ANSI: 6 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] 240328704 512-byte logical blocks: (123 GB/115 GiB) Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] Write Protect is off Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA Dec 14 19:57:39 volumio kernel: sda: sda1 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f8 00 00 01 00 Dec 14 19:57:39 volumio kernel: critical medium error, dev sda, sector 240328696 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f9 00 00 01 00 Dec 14 19:57:39 volumio kernel: critical medium error, dev sda, sector 240328697 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:57:39 volumio kernel: Buffer I/O error on dev sda, logical block 30041087, async page read Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f8 00 00 01 00 Dec 14 19:57:39 volumio kernel: critical medium error, dev sda, sector 240328696 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Dec 14 19:57:39 volumio volumio[943]: error: Cannot associate FS Label, not mounting Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Dec 14 19:57:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0e 53 1f f9 00 00 01 00 Dec 14 19:57:39 volumio kernel: critical medium error, dev sda, sector 240328697 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Dec 14 19:57:39 volumio kernel: Buffer I/O error on dev sda1, logical block 30041083, async page read Dec 14 19:57:41 volumio go-librespot[2322]: time="2025-12-14T19:57:41+08:00" level=debug msg="completed keyexchange" Dec 14 19:57:42 volumio go-librespot[2322]: time="2025-12-14T19:57:42+08:00" level=debug msg="completed challenge" Dec 14 19:57:42 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:57:42 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Dec 14 19:57:42 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:42 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:42 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:57:42 volumio go-librespot[2322]: time="2025-12-14T19:57:42+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:57:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:57:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:57:42 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: socket hang up Dec 14 19:57:42 volumio volumio[943]: at connResetException (internal/errors.js:607:14) Dec 14 19:57:42 volumio volumio[943]: at Socket.socketOnEnd (_http_client.js:493:23) Dec 14 19:57:42 volumio volumio[943]: at Socket.emit (events.js:327:22) Dec 14 19:57:42 volumio volumio[943]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 14 19:57:42 volumio volumio[943]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 14 19:57:42 volumio volumio[943]: (node:943) 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: 30) Dec 14 19:57:42 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:57:43 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:45 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:45 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:57:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Dec 14 19:57:45 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:57:45 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:57:45 volumio go-librespot[2335]: Librespot-go daemon starting... Dec 14 19:57:45 volumio go-librespot[2335]: time="2025-12-14T19:57:45+08:00" level=info msg="generated new device id: c3ce7d4223c1dfbfe1c7d08b8374910e7f6de0c7" Dec 14 19:57:45 volumio go-librespot[2335]: time="2025-12-14T19:57:45+08:00" level=debug msg="stored credentials not found" Dec 14 19:57:46 volumio go-librespot[2335]: time="2025-12-14T19:57:46+08:00" level=debug msg="obtained new client token: AAA6aELeYmhQ5Ifupp6vqTXVeji9CjtkLOTY/5VkaMPdBv91m+uLIs+EpUY0tuXIidMCx2X5XdZrCayIcM9wb6CR+V/queWvCFr2zTAB9h7Jc8aCJexwlyGeJ/jH8ZaxBHFqxi/NWOKpNvIR1CJPMaaP4518QFGgIn4N2DveClI9TNKuXe0gk6Qxn1iojpQT4Q6XFqV7kF6P1DDxS7J+o5hOx1uXjWWyf3azplWBNI1ERaKaZLCfX/6ZzmSvL6I+sg==" Dec 14 19:57:47 volumio go-librespot[2335]: time="2025-12-14T19:57:47+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:57:48 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:48 volumio go-librespot[2335]: time="2025-12-14T19:57:48+08:00" level=debug msg="new websocket client" Dec 14 19:57:48 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:57:49 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:50 volumio go-librespot[2335]: time="2025-12-14T19:57:50+08:00" level=debug msg="completed keyexchange" Dec 14 19:57:50 volumio volumio[943]: verbose: New Socket.io Connection to 192.168.101.4 from 192.168.101.3 UA: Mozilla/5.0 (Linux; Android 15; SM-S9010 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Total Clients: 9 Dec 14 19:57:50 volumio volumio[943]: verbose: New Socket.io Connection to 192.168.101.4 from 192.168.101.3 UA: Mozilla/5.0 (Linux; Android 15; SM-S9010 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Total Clients: 10 Dec 14 19:57:50 volumio go-librespot[2335]: time="2025-12-14T19:57:50+08:00" level=debug msg="completed challenge" Dec 14 19:57:50 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:50 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:50 volumio go-librespot[2335]: time="2025-12-14T19:57:50+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Dec 14 19:57:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 14 19:57:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 14 19:57:50 volumio volumio[943]: info: Connection to go-librespot Websocket closed Dec 14 19:57:51 volumio volumio[943]: info: Getting Spotify volume Dec 14 19:57:51 volumio volumio[943]: (node:943) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:51 volumio volumio[943]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Dec 14 19:57:51 volumio volumio[943]: (node:943) 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: 31) Dec 14 19:57:51 volumio volumio[943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 11 Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:51 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:51 volumio volumio[943]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Dec 14 19:57:51 volumio volumio[943]: verbose: New Socket.io Connection to 192.168.101.4 from 192.168.101.3 UA: Mozilla/5.0 (Linux; Android 15; SM-S9010 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Total Clients: 11 Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::volumioGetVisibleSources Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:51 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::volumioGetQueue Dec 14 19:57:51 volumio volumio[943]: info: CoreStateMachine::getQueue Dec 14 19:57:51 volumio volumio[943]: info: CorePlayQueue::getQueue Dec 14 19:57:51 volumio volumio[943]: info: Listing playlists Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 14 19:57:51 volumio volumio[943]: info: Received Get System Info Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 14 19:57:51 volumio volumio[943]: info: Discovery: Getting this device information Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:51 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 14 19:57:51 volumio volumio[943]: info: CoreCommandRouter::volumioGetState Dec 14 19:57:51 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:53 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:53 volumio volumio[943]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 14 19:57:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 14 19:57:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Dec 14 19:57:53 volumio systemd[1]: Stopped go-librespot Daemon. Dec 14 19:57:53 volumio systemd[1]: Started go-librespot Daemon. Dec 14 19:57:53 volumio go-librespot[2343]: Librespot-go daemon starting... Dec 14 19:57:54 volumio go-librespot[2343]: time="2025-12-14T19:57:54+08:00" level=info msg="generated new device id: fe1a70d01de6f3d5a688ec7bffdb277b19479399" Dec 14 19:57:54 volumio go-librespot[2343]: time="2025-12-14T19:57:54+08:00" level=debug msg="stored credentials not found" Dec 14 19:57:54 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri Dec 14 19:57:54 volumio volumio[943]: info: [1765713474586] [80s80s] handleBrowseUri curUri: 80s80s Dec 14 19:57:54 volumio volumio[943]: info: Preload queue cleared Dec 14 19:57:55 volumio volumio[943]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri Dec 14 19:57:55 volumio volumio[943]: info: [1765713475754] [80s80s] handleBrowseUri curUri: 80s80s/eighties Dec 14 19:57:55 volumio volumio[943]: info: [1765713475755] [80s80s] getRadioContent url: eighties Dec 14 19:57:55 volumio wpa_supplicant[784]: wlan0: Failed to initiate sched scan Dec 14 19:57:55 volumio volumio[943]: info: Preload queue cleared Dec 14 19:57:56 volumio volumio[943]: info: Initializing connection to go-librespot Websocket Dec 14 19:57:56 volumio go-librespot[2343]: time="2025-12-14T19:57:56+08:00" level=debug msg="new websocket client" Dec 14 19:57:56 volumio volumio[943]: info: Connection to go-librespot Websocket established Dec 14 19:57:58 volumio go-librespot[2343]: time="2025-12-14T19:57:58+08:00" level=debug msg="obtained new client token: AAB4WtNE157xg6PZlAC4hOyuqSjPH+aujB9TVfAF2JPaKS4e8YAIHAnSbEOPF3h+3cIJv7PrgvqTV0RgDnRfSour2YjG190j16vIhtO+5v0Q7T5iNLDTVlbbhUi/lfIP71d0LQy3ArG1hpoVUZhtlbnQC5gNOLszRx1UHpeCpnFp490GtFH6Gsqgw2rKgr0R8kD7TMX2WDtBIV6or2s25hYMCb2UW0XURD7fGcMJRT8aaZD9l3yaGjSRrKbHZ+Nilw==" Dec 14 19:57:58 volumio volumio[943]: info: Preload queue cleared Dec 14 19:57:58 volumio volumio[943]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::ClearQueue Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::stop Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 14 19:57:58 volumio volumio[943]: info: CorePlayQueue::clearPlayQueue Dec 14 19:57:58 volumio volumio[943]: info: CorePlayQueue::saveQueue Dec 14 19:57:58 volumio volumio[943]: info: CoreCommandRouter::volumioPushQueue Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::addQueueItems Dec 14 19:57:58 volumio volumio[943]: info: CorePlayQueue::addQueueItems Dec 14 19:57:58 volumio volumio[943]: info: Preload queue cleared Dec 14 19:57:58 volumio volumio[943]: info: Adding Item to queue: webeighties/2 Dec 14 19:57:58 volumio volumio[943]: info: Exploding uri webeighties/2 in service 80s80s Dec 14 19:57:58 volumio volumio[943]: info: [1765713478477] [80s80s] explodeUri: webeighties/2 Dec 14 19:57:58 volumio volumio[943]: info: CoreCommandRouter::volumioPushQueue Dec 14 19:57:58 volumio volumio[943]: info: CorePlayQueue::saveQueue Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::updateTrackBlock Dec 14 19:57:58 volumio volumio[943]: info: CorePlayQueue::getTrackBlock Dec 14 19:57:58 volumio volumio[943]: info: CoreCommandRouter::volumioPlay Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::play index 0 Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::stop Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::play index undefined Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 14 19:57:58 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:58 volumio volumio[943]: info: CoreStateMachine::startPlaybackTimer Dec 14 19:57:58 volumio volumio[943]: info: CorePlayQueue::getTrack 0 Dec 14 19:57:58 volumio volumio[943]: info: [1765713478495] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/love/mp3-192/volumio Dec 14 19:57:58 volumio volumio[943]: info: [1765713478496] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=85&count=2 Dec 14 19:57:58 volumio volumio[943]: info: [1765713478869] [80s80s] Failed to query api, status code: 404 Dec 14 19:57:58 volumio volumio[943]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 14 19:57:58 volumio volumio[943]: Error: ENOENT: no such file or directory, open '/data/plugins/music_service/80s80s/fake-data.json' Dec 14 19:57:58 volumio volumio[943]: at Object.openSync (fs.js:476:3) Dec 14 19:57:58 volumio volumio[943]: at Object.readFileSync (fs.js:377:35) Dec 14 19:57:58 volumio volumio[943]: at ClientRequest. (/data/plugins/music_service/80s80s/index.js:485:23) Dec 14 19:57:58 volumio volumio[943]: at Object.onceWrapper (events.js:422:26) Dec 14 19:57:58 volumio volumio[943]: at ClientRequest.emit (events.js:315:20) Dec 14 19:57:58 volumio volumio[943]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27) Dec 14 19:57:58 volumio volumio[943]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17) Dec 14 19:57:58 volumio volumio[943]: at Socket.socketOnData (_http_client.js:509:22) Dec 14 19:57:58 volumio volumio[943]: at Socket.emit (events.js:315:20) Dec 14 19:57:58 volumio volumio[943]: at addChunk (internal/streams/readable.js:309:12) Dec 14 19:57:58 volumio volumio[943]: at readableAddChunk (internal/streams/readable.js:284:9) Dec 14 19:57:58 volumio volumio[943]: at Socket.Readable.push (internal/streams/readable.js:223:10) Dec 14 19:57:58 volumio volumio[943]: at TCP.onStreamRead (internal/stream_base_commons.js:188:23) { Dec 14 19:57:58 volumio volumio[943]: errno: -2, Dec 14 19:57:58 volumio volumio[943]: syscall: 'open', Dec 14 19:57:58 volumio volumio[943]: code: 'ENOENT', Dec 14 19:57:58 volumio volumio[943]: path: '/data/plugins/music_service/80s80s/fake-data.json' Dec 14 19:57:58 volumio volumio[943]: } Dec 14 19:57:58 volumio volumio[943]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 14 19:57:59 volumio go-librespot[2343]: time="2025-12-14T19:57:59+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 14 19:57:59 volumio sudo[2362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-14 19:56 Dec 14 19:57:59 volumio sudo[2362]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"