-- Logs begin at Sun 2024-10-06 22:28:45 +07, end at Sun 2024-10-06 22:32:08 +07. -- Oct 06 22:31:00 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: youtube2 , handleBrowseUri Oct 06 22:31:00 volumio volumio[1191]: info: [youtube2-browse] browseUri: youtube2 Oct 06 22:31:00 volumio volumio[1191]: info: CoreCommandRouter::volumioGetQueue Oct 06 22:31:00 volumio volumio[1191]: info: CoreStateMachine::getQueue Oct 06 22:31:00 volumio volumio[1191]: info: CorePlayQueue::getQueue Oct 06 22:31:02 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:02 volumio volumio[1191]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 06 22:31:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Oct 06 22:31:02 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 22:31:02 volumio systemd[1]: Started go-librespot Daemon. Oct 06 22:31:02 volumio go-librespot[2371]: Librespot-go daemon starting... Oct 06 22:31:02 volumio go-librespot[2371]: time="2024-10-06T22:31:02+07:00" level=info msg="generated new device id: ad8725f3d0e2759157c74154ee91c484914500c8" Oct 06 22:31:02 volumio go-librespot[2371]: time="2024-10-06T22:31:02+07:00" level=debug msg="stored credentials found for 31zsvgwonuapopmymyhqfxpedbny" Oct 06 22:31:02 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:02 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:02 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:02 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:03 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:03 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:03 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:03 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:04 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:04 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:04 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:04 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:05 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:05 volumio go-librespot[2371]: time="2024-10-06T22:31:05+07:00" level=debug msg="new websocket client" Oct 06 22:31:05 volumio volumio[1191]: info: Connection to go-librespot Websocket established Oct 06 22:31:06 volumio volumio[1191]: info: Preload queue cleared Oct 06 22:31:06 volumio volumio[1191]: info: Preload queue cleared Oct 06 22:31:06 volumio go-librespot[2371]: time="2024-10-06T22:31:06+07: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]" Oct 06 22:31:06 volumio go-librespot[2371]: time="2024-10-06T22:31:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 06 22:31:06 volumio go-librespot[2371]: time="2024-10-06T22:31:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 06 22:31:06 volumio go-librespot[2371]: time="2024-10-06T22:31:06+07:00" level=debug msg="zeroconf server listening on port 36007" Oct 06 22:31:08 volumio volumio[1191]: info: Getting Spotify volume Oct 06 22:31:08 volumio volumio[1191]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 06 22:31:08 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:08 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:31:08 volumio volumio[1191]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 06 22:31:08 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:08 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 06 22:31:08 volumio volumio[1191]: info: CoreCommandRouter::volumioGetVisibleSources Oct 06 22:31:08 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 22:31:08 volumio volumio[1191]: info: Listing playlists Oct 06 22:31:08 volumio volumio[1191]: info: CoreCommandRouter::volumioGetQueue Oct 06 22:31:08 volumio volumio[1191]: info: CoreStateMachine::getQueue Oct 06 22:31:08 volumio volumio[1191]: info: CorePlayQueue::getQueue Oct 06 22:31:14 volumio go-librespot[2371]: time="2024-10-06T22:31:14+07:00" level=debug msg="obtained new client token: AACSERTxIDaZtPBMyMv5RBS02yrISCE19+ddzln8NUWxfs2KtMxtxJXhLbY8IIfZeAidY3o8cXsb6ctgtM8bsd6hIUfZMpruvw6zG7ZRcagbnsrkvwsH9XNjYdIMYCdq3RBr4o/ZTJpTSZEtqRJeXIeTYf+8mtrCesmmtB7q6ACPpcJQI42NcpTAu/piH63kt+L8DL9LYr1pJrhFEgWauns57o8K52nh3UZJgNkDiqqBmW2LFrznG546FXi9" Oct 06 22:31:16 volumio go-librespot[2371]: time="2024-10-06T22:31:16+07:00" level=debug msg="completed keyexchange" Oct 06 22:31:17 volumio go-librespot[2371]: time="2024-10-06T22:31:17+07:00" level=debug msg="completed challenge" Oct 06 22:31:18 volumio go-librespot[2371]: time="2024-10-06T22:31:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 06 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 06 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 06 22:31:18 volumio volumio[1191]: (node:1191) UnhandledPromiseRejectionWarning: Error: socket hang up Oct 06 22:31:18 volumio volumio[1191]: at connResetException (internal/errors.js:639:14) Oct 06 22:31:18 volumio volumio[1191]: at Socket.socketOnEnd (_http_client.js:499:23) Oct 06 22:31:18 volumio volumio[1191]: at Socket.emit (events.js:412:35) Oct 06 22:31:18 volumio volumio[1191]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 06 22:31:18 volumio volumio[1191]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 06 22:31:18 volumio volumio[1191]: (node:1191) 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: 12) Oct 06 22:31:18 volumio volumio[1191]: info: Connection to go-librespot Websocket closed Oct 06 22:31:21 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:21 volumio volumio[1191]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 06 22:31:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Oct 06 22:31:21 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 22:31:21 volumio systemd[1]: Started go-librespot Daemon. Oct 06 22:31:21 volumio go-librespot[2418]: Librespot-go daemon starting... Oct 06 22:31:21 volumio go-librespot[2418]: time="2024-10-06T22:31:21+07:00" level=info msg="generated new device id: 99779d2c2e92c34f0b26aabeb17e910cc20af52c" Oct 06 22:31:21 volumio go-librespot[2418]: time="2024-10-06T22:31:21+07:00" level=debug msg="stored credentials found for 31zsvgwonuapopmymyhqfxpedbny" Oct 06 22:31:22 volumio ntpd[1700]: Soliciting pool server 27.71.27.209 Oct 06 22:31:22 volumio go-librespot[2418]: time="2024-10-06T22:31:22+07: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]" Oct 06 22:31:22 volumio go-librespot[2418]: time="2024-10-06T22:31:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 06 22:31:22 volumio go-librespot[2418]: time="2024-10-06T22:31:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 06 22:31:22 volumio go-librespot[2418]: time="2024-10-06T22:31:22+07:00" level=debug msg="zeroconf server listening on port 34981" Oct 06 22:31:22 volumio go-librespot[2418]: time="2024-10-06T22:31:22+07:00" level=debug msg="obtained new client token: AADnIXeIhCOEQnCL0Jente87YlL3wvRDEb9qSzDqwhc9TsuDw+z4Aohl6z/mSVDv8Ew9S2dK5BrH2XwGlN9JxyFVZfY1XZqUtckY9AB74jK8zdy3RmtH6WdK4bhz7GouJszA2vzWNurhiv8YGfxv/sKetlyRIgwXbIsYlHn48UtcstLJPdTM5I6yGv0bxEAMXF/YubO2oEhOFUybSFwgALVaBjE9ID8MbVohCVxnvhPf/u1XegijUf5LEiq+" Oct 06 22:31:22 volumio go-librespot[2418]: time="2024-10-06T22:31:22+07:00" level=debug msg="completed keyexchange" Oct 06 22:31:23 volumio go-librespot[2418]: time="2024-10-06T22:31:23+07:00" level=debug msg="completed challenge" Oct 06 22:31:23 volumio go-librespot[2418]: time="2024-10-06T22:31:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 06 22:31:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 06 22:31:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 06 22:31:24 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:24 volumio volumio[1191]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:24 volumio ntpd[1700]: Soliciting pool server 103.130.217.41 Oct 06 22:31:24 volumio ntpd[1700]: Soliciting pool server 115.165.161.155 Oct 06 22:31:25 volumio ntpd[1700]: Soliciting pool server 103.184.124.23 Oct 06 22:31:25 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:25 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:25 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:25 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 06 22:31:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Oct 06 22:31:26 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 22:31:26 volumio systemd[1]: Started go-librespot Daemon. Oct 06 22:31:26 volumio go-librespot[2437]: Librespot-go daemon starting... Oct 06 22:31:26 volumio go-librespot[2437]: time="2024-10-06T22:31:26+07:00" level=info msg="generated new device id: 643560053c9aed9ddf21fae000ae1039a0d24e21" Oct 06 22:31:26 volumio go-librespot[2437]: time="2024-10-06T22:31:26+07:00" level=debug msg="stored credentials found for 31zsvgwonuapopmymyhqfxpedbny" Oct 06 22:31:26 volumio kernel: pcieport 0000:00:1c.7: AER: Corrected error message received from 0000:02:00.0 Oct 06 22:31:26 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Receiver ID) Oct 06 22:31:26 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000080/00002000 Oct 06 22:31:26 volumio kernel: ath9k 0000:02:00.0: [ 7] BadDLLP Oct 06 22:31:27 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:27 volumio go-librespot[2437]: time="2024-10-06T22:31:27+07:00" level=debug msg="new websocket client" Oct 06 22:31:27 volumio volumio[1191]: info: Connection to go-librespot Websocket established Oct 06 22:31:27 volumio go-librespot[2437]: time="2024-10-06T22:31:27+07: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]" Oct 06 22:31:27 volumio go-librespot[2437]: time="2024-10-06T22:31:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 06 22:31:27 volumio go-librespot[2437]: time="2024-10-06T22:31:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 06 22:31:27 volumio go-librespot[2437]: time="2024-10-06T22:31:27+07:00" level=debug msg="zeroconf server listening on port 38977" Oct 06 22:31:27 volumio go-librespot[2437]: time="2024-10-06T22:31:27+07:00" level=debug msg="obtained new client token: AACgkplksE3OHrxF4vq20OoZM6OkS/YwTVI5szsPgvy4TzCDavlJfZYDh4tWhBbEdQzX5zTvjR0qlidOg5fueSvOqLA94bjuwTFbeFrUlQgI+ZNcDs4xWR+fq1nKao7zVSNOzgmKJzpMmgFKHYoHIP2ynN2cAEUew/HhVrEkUW6fG0STM7ZEe9INg7DukcSr2bXPfi4qlNSnwWEXbY84kwkLt5c/4Ucj29R9YxzwnPTDxMJqdFRrRFv2Pzjc" Oct 06 22:31:27 volumio go-librespot[2437]: time="2024-10-06T22:31:27+07:00" level=debug msg="completed keyexchange" Oct 06 22:31:28 volumio go-librespot[2437]: time="2024-10-06T22:31:28+07:00" level=debug msg="completed challenge" Oct 06 22:31:28 volumio go-librespot[2437]: time="2024-10-06T22:31:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 06 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 06 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 06 22:31:28 volumio volumio[1191]: info: Connection to go-librespot Websocket closed Oct 06 22:31:30 volumio volumio[1191]: info: Getting Spotify volume Oct 06 22:31:30 volumio volumio[1191]: (node:1191) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:30 volumio volumio[1191]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 06 22:31:30 volumio volumio[1191]: (node:1191) 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: 13) Oct 06 22:31:30 volumio volumio[1191]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 06 22:31:30 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:30 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:31:31 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:31 volumio volumio[1191]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 06 22:31:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Oct 06 22:31:31 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 22:31:31 volumio systemd[1]: Started go-librespot Daemon. Oct 06 22:31:31 volumio go-librespot[2456]: Librespot-go daemon starting... Oct 06 22:31:31 volumio go-librespot[2456]: time="2024-10-06T22:31:31+07:00" level=info msg="generated new device id: b9b90dd00eb92a3707d984b7685adca73e9f100f" Oct 06 22:31:31 volumio go-librespot[2456]: time="2024-10-06T22:31:31+07:00" level=debug msg="stored credentials found for 31zsvgwonuapopmymyhqfxpedbny" Oct 06 22:31:32 volumio go-librespot[2456]: time="2024-10-06T22:31:32+07: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]" Oct 06 22:31:32 volumio go-librespot[2456]: time="2024-10-06T22:31:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 06 22:31:32 volumio go-librespot[2456]: time="2024-10-06T22:31:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 06 22:31:32 volumio go-librespot[2456]: time="2024-10-06T22:31:32+07:00" level=debug msg="zeroconf server listening on port 39803" Oct 06 22:31:32 volumio go-librespot[2456]: time="2024-10-06T22:31:32+07:00" level=debug msg="obtained new client token: AADqEI49Xb30DPLNcXwGGq+qZ/bPWEh9HQaXxpvW5gtmmfFKjsW77m+e+KW4dgUk2SnqZWXREpc6FiCmgcwqBCAK0WZMUtv1ejj3GScTRqVzJ7FJ0DiLDP9o0kxKTxj+A0VCnSa3YNhILcAxO6W5hxKUvjpv+OS8mrzf0RTuu9E5by5ueMerwalPhia8i0dVQKFUD1tDnO8CuquTlvk+S/cxV2+PcAGgdugkFSkXtvgn31zvl5L4LbtT6mnJ" Oct 06 22:31:32 volumio go-librespot[2456]: time="2024-10-06T22:31:32+07:00" level=debug msg="completed keyexchange" Oct 06 22:31:33 volumio go-librespot[2456]: time="2024-10-06T22:31:33+07:00" level=debug msg="completed challenge" Oct 06 22:31:33 volumio go-librespot[2456]: time="2024-10-06T22:31:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 06 22:31:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 06 22:31:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 06 22:31:34 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:34 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:34 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:34 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:34 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:34 volumio volumio[1191]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 06 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Oct 06 22:31:36 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 22:31:36 volumio systemd[1]: Started go-librespot Daemon. Oct 06 22:31:36 volumio go-librespot[2474]: Librespot-go daemon starting... Oct 06 22:31:36 volumio go-librespot[2474]: time="2024-10-06T22:31:36+07:00" level=info msg="generated new device id: d56229d4818f7123edc8a4243df0511d7d1702cc" Oct 06 22:31:36 volumio go-librespot[2474]: time="2024-10-06T22:31:36+07:00" level=debug msg="stored credentials found for 31zsvgwonuapopmymyhqfxpedbny" Oct 06 22:31:36 volumio go-librespot[2474]: time="2024-10-06T22:31:36+07: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]" Oct 06 22:31:36 volumio go-librespot[2474]: time="2024-10-06T22:31:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 06 22:31:36 volumio go-librespot[2474]: time="2024-10-06T22:31:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 06 22:31:36 volumio go-librespot[2474]: time="2024-10-06T22:31:36+07:00" level=debug msg="zeroconf server listening on port 45767" Oct 06 22:31:37 volumio wpa_supplicant[1064]: wlan0: CTRL-EVENT-BEACON-LOSS Oct 06 22:31:37 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:37 volumio go-librespot[2474]: time="2024-10-06T22:31:37+07:00" level=debug msg="new websocket client" Oct 06 22:31:37 volumio volumio[1191]: info: Connection to go-librespot Websocket established Oct 06 22:31:38 volumio go-librespot[2474]: time="2024-10-06T22:31:38+07:00" level=debug msg="obtained new client token: AAAhdG96LWuvQF9yeTzwdKWwR54t5NMGZCZLW72Hx46LSswpvKFBGjRRwRo4Wx6uH8h2VhJ98wlpwYle00aERguNKqqEavEEs2fhSlsCc1gLobY4Nb8lcDmnoNeKgy6bQ04bglnUCW+f1f28i9hkSoWWxUK0WW3Gk5asw4Mx248u5V9VWqesoUNLgIpCqnwlJPmw6HNOUSXcBf9imY071un2QbdIcK+XK8kYZX/kCnJOrhWuGt88/TVWIA==" Oct 06 22:31:38 volumio go-librespot[2474]: time="2024-10-06T22:31:38+07:00" level=debug msg="completed keyexchange" Oct 06 22:31:39 volumio wpa_supplicant[1064]: wlan0: CTRL-EVENT-BEACON-LOSS Oct 06 22:31:39 volumio go-librespot[2474]: time="2024-10-06T22:31:39+07:00" level=debug msg="completed challenge" Oct 06 22:31:39 volumio go-librespot[2474]: time="2024-10-06T22:31:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 06 22:31:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 06 22:31:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 06 22:31:39 volumio volumio[1191]: info: Connection to go-librespot Websocket closed Oct 06 22:31:40 volumio wpa_supplicant[1064]: wlan0: CTRL-EVENT-BEACON-LOSS Oct 06 22:31:40 volumio volumio[1191]: info: Getting Spotify volume Oct 06 22:31:40 volumio volumio[1191]: (node:1191) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:40 volumio volumio[1191]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 06 22:31:40 volumio volumio[1191]: (node:1191) 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: 14) Oct 06 22:31:40 volumio volumio[1191]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 06 22:31:40 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:40 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:31:40 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:40 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:40 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:40 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:41 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:41 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:41 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:41 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:42 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:42 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:42 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:42 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:42 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:42 volumio volumio[1191]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 06 22:31:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 06 22:31:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Oct 06 22:31:42 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 22:31:42 volumio systemd[1]: Started go-librespot Daemon. Oct 06 22:31:42 volumio go-librespot[2496]: Librespot-go daemon starting... Oct 06 22:31:42 volumio go-librespot[2496]: time="2024-10-06T22:31:42+07:00" level=info msg="generated new device id: b56c9544b5a02c75dce80035fd392df599aa8313" Oct 06 22:31:42 volumio go-librespot[2496]: time="2024-10-06T22:31:42+07:00" level=debug msg="stored credentials found for 31zsvgwonuapopmymyhqfxpedbny" Oct 06 22:31:43 volumio volumio[1191]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::volumioGetVisibleSources Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 06 22:31:43 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 06 22:31:43 volumio volumio[1191]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::volumioGetVisibleSources Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 22:31:44 volumio volumio[1191]: info: Listing playlists Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 06 22:31:44 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 06 22:31:45 volumio volumio[1191]: info: Initializing connection to go-librespot Websocket Oct 06 22:31:45 volumio go-librespot[2496]: time="2024-10-06T22:31:45+07:00" level=debug msg="new websocket client" Oct 06 22:31:45 volumio volumio[1191]: info: Connection to go-librespot Websocket established Oct 06 22:31:46 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 06 22:31:46 volumio volumio[1191]: info: Received Get System Info Oct 06 22:31:46 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 06 22:31:46 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 06 22:31:46 volumio volumio[1191]: info: Discovery: Getting this device information Oct 06 22:31:46 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:46 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 22:31:46 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 06 22:31:46 volumio wpa_supplicant[1064]: wlan0: CTRL-EVENT-BEACON-LOSS Oct 06 22:31:47 volumio wpa_supplicant[1064]: wlan0: CTRL-EVENT-BEACON-LOSS Oct 06 22:31:48 volumio volumio[1191]: info: Getting Spotify volume Oct 06 22:31:48 volumio volumio[1191]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 06 22:31:48 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:31:48 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:31:51 volumio wpa_supplicant[1064]: wlan0: CTRL-EVENT-BEACON-LOSS Oct 06 22:31:51 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:31:51 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:31:51 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:31:51 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:31:52 volumio wpa_supplicant[1064]: wlan0: CTRL-EVENT-BEACON-LOSS Oct 06 22:31:55 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: youtube2 , handleBrowseUri Oct 06 22:31:55 volumio volumio[1191]: info: [youtube2-browse] browseUri: youtube2 Oct 06 22:31:55 volumio volumio[1191]: info: CoreCommandRouter::volumioGetQueue Oct 06 22:31:55 volumio volumio[1191]: info: CoreStateMachine::getQueue Oct 06 22:31:55 volumio volumio[1191]: info: CorePlayQueue::getQueue Oct 06 22:31:55 volumio volumio[1191]: info: Preload queue cleared Oct 06 22:31:55 volumio volumio[1191]: info: Preload queue cleared Oct 06 22:31:57 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: youtube2 , handleBrowseUri Oct 06 22:31:57 volumio volumio[1191]: info: [youtube2-browse] browseUri: youtube2/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22UC-9-kyTW8ZkZNDHQJ6FgpwQ%22%7D%7D Oct 06 22:31:59 volumio volumio[1191]: info: Preload queue cleared Oct 06 22:31:59 volumio volumio[1191]: info: Preload queue cleared Oct 06 22:32:02 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 06 22:32:02 volumio volumio[1191]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 06 22:32:02 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 06 22:32:02 volumio volumio[1191]: info: Received Get System Version Oct 06 22:32:02 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 22:32:02 volumio volumio[1191]: info: Received Get System Info Oct 06 22:32:02 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 06 22:32:02 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 06 22:32:02 volumio volumio[1191]: info: Discovery: Getting this device information Oct 06 22:32:02 volumio volumio[1191]: info: CoreCommandRouter::volumioGetState Oct 06 22:32:02 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 22:32:02 volumio go-librespot[2496]: time="2024-10-06T22:32:02+07: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]" Oct 06 22:32:02 volumio go-librespot[2496]: time="2024-10-06T22:32:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 06 22:32:02 volumio go-librespot[2496]: time="2024-10-06T22:32:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 06 22:32:02 volumio go-librespot[2496]: time="2024-10-06T22:32:02+07:00" level=debug msg="zeroconf server listening on port 40047" Oct 06 22:32:04 volumio go-librespot[2496]: time="2024-10-06T22:32:04+07:00" level=debug msg="obtained new client token: AAA2vYQGtoWrX2UTCglucAaMWT8Fk78lpESADKreTxfX6hFG8skmT97W9gBNmOtQCT99Mwb/aX9/zgnkZnahDSJ/9V/88/23Mcqc51FunT7upqow9miDnakBc6pGuWlpUds0k2gbNfu+7FnoiWYKWTE98XRWFFnkTwLIqiUCkRJ7mtQRuSD4GYXbYZLmTR6UprIOxDwXnAxLuN/8iaW/HYoAbSY8c34kk7fSEz/1OzlFWmWoHUNqMFXRXBEc" Oct 06 22:32:04 volumio go-librespot[2496]: time="2024-10-06T22:32:04+07:00" level=debug msg="completed keyexchange" Oct 06 22:32:05 volumio go-librespot[2496]: time="2024-10-06T22:32:05+07:00" level=debug msg="completed challenge" Oct 06 22:32:05 volumio go-librespot[2496]: time="2024-10-06T22:32:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 06 22:32:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 06 22:32:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 06 22:32:05 volumio volumio[1191]: (node:1191) UnhandledPromiseRejectionWarning: Error: socket hang up Oct 06 22:32:05 volumio volumio[1191]: at connResetException (internal/errors.js:639:14) Oct 06 22:32:05 volumio volumio[1191]: at Socket.socketOnEnd (_http_client.js:499:23) Oct 06 22:32:05 volumio volumio[1191]: at Socket.emit (events.js:412:35) Oct 06 22:32:05 volumio volumio[1191]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 06 22:32:05 volumio volumio[1191]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 06 22:32:05 volumio volumio[1191]: (node:1191) 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: 15) Oct 06 22:32:05 volumio volumio[1191]: info: Connection to go-librespot Websocket closed Oct 06 22:32:06 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:32:06 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:32:06 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:32:06 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioNext Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::next Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::next Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::sendMpdCommand next Oct 06 22:32:06 volumio volumio[1191]: info: sendMpdCommand next took 3 milliseconds Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::getState Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::sendMpdCommand status Oct 06 22:32:06 volumio volumio[1191]: info: Oct 06 22:32:06 volumio volumio[1191]: ---------------------------- MPD announces state update: player Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::getState Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::sendMpdCommand status Oct 06 22:32:06 volumio volumio[1191]: info: Oct 06 22:32:06 volumio volumio[1191]: ---------------------------- MPD announces state update: player Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::getState Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::sendMpdCommand status Oct 06 22:32:06 volumio volumio[1191]: info: Oct 06 22:32:06 volumio volumio[1191]: ---------------------------- MPD announces state update: player Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::getState Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::sendMpdCommand status Oct 06 22:32:06 volumio volumio[1191]: info: sendMpdCommand status took 1 milliseconds Oct 06 22:32:06 volumio volumio[1191]: info: sendMpdCommand status took 1 milliseconds Oct 06 22:32:06 volumio volumio[1191]: info: sendMpdCommand status took 1 milliseconds Oct 06 22:32:06 volumio volumio[1191]: info: sendMpdCommand status took 1 milliseconds Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::parseState Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::parseState Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::parseState Oct 06 22:32:06 volumio volumio[1191]: verbose: ControllerMpd::parseState Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::getQueue Oct 06 22:32:06 volumio volumio[1191]: info: CorePlayQueue::getQueue Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::getQueue Oct 06 22:32:06 volumio volumio[1191]: info: CorePlayQueue::getQueue Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::servicePushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: CorePlayQueue::getTrack 0 Oct 06 22:32:06 volumio volumio[1191]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 06 22:32:06 volumio volumio[1191]: verbose: CURRENT POSITION 0 Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::syncState stateService stop Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::syncState currentStatus play Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::stPlaybackTimer Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::servicePushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: CorePlayQueue::getTrack 0 Oct 06 22:32:06 volumio volumio[1191]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 06 22:32:06 volumio volumio[1191]: verbose: CURRENT POSITION 0 Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::syncState stateService stop Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::syncState currentStatus stop Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: No code Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: ControllerMpd::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::servicePushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: CorePlayQueue::getTrack 0 Oct 06 22:32:06 volumio volumio[1191]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 06 22:32:06 volumio volumio[1191]: verbose: CURRENT POSITION 0 Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::syncState stateService stop Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::syncState currentStatus stop Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: No code Oct 06 22:32:06 volumio volumio[1191]: info: CoreStateMachine::pushState Oct 06 22:32:06 volumio volumio[1191]: info: CoreCommandRouter::volumioPushState Oct 06 22:32:06 volumio volumio[1191]: info: ------------------------------ 12ms Oct 06 22:32:06 volumio volumio[1191]: info: ------------------------------ 13ms Oct 06 22:32:06 volumio volumio[1191]: info: ------------------------------ 13ms Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:06 volumio volumio[1191]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 06 22:32:07 volumio kernel: pcieport 0000:00:1c.7: AER: Multiple Corrected error message received from 0000:02:00.0 Oct 06 22:32:07 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Oct 06 22:32:07 volumio kernel: ath9k 0000:02:00.0: device [168c:0036] error status/mask=00000001/00002000 Oct 06 22:32:07 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Oct 06 22:32:08 volumio volumio[1191]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 22:32:08 volumio volumio[1191]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Oct 06 22:32:08 volumio volumio[1191]: code: 'auth/network-request-failed', Oct 06 22:32:08 volumio volumio[1191]: a: null Oct 06 22:32:08 volumio volumio[1191]: } Oct 06 22:32:08 volumio volumio[1191]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 22:32:08 volumio sudo[2611]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-06 22:31 Oct 06 22:32:08 volumio sudo[2611]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"