-- Logs begin at Tue 2025-01-21 23:01:18 KST, end at Wed 2025-01-22 01:19:43 KST. -- Jan 22 01:18:02 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:02 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93839. Jan 22 01:18:02 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:02 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: Librespot-go daemon starting... Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09:00" level=info msg="generated new device id: 7f19365c00349daea982869eddde68d0745bb65d" Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09: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]" Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09: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]" Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09: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]" Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09:00" level=debug msg="zeroconf server listening on port 33283" Jan 22 01:18:02 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09:00" level=debug msg="new websocket client" Jan 22 01:18:02 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09:00" level=debug msg="obtained new client token: AAATmJ6Bgflb1Hz562t1AvRX/DwOaJ1FO/LZfKD9jowNXOQJL8xFHp43ZR8MMFAW4IK1Ddvnc3Oj0fMlW4gc0pRDn5bsJ9xm0kWTc7/VGBgAylh6dB+daCiCHgKQ4ZZN6no6i99TgIgE0UVPJm6nNmPy+fsTVSiXAl+bNnvxURtmszHkfvrU55799S737jOLs2vedyReIXvO3DwrjXQoqlGKqODLB47bc1i4gmj6uwjBqhmQITXHkhXeonEprDM8" Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:02 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:02+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:03 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:03+09:00" level=debug msg="completed challenge" Jan 22 01:18:03 volumio-ap3 go-librespot[5724]: time="2025-01-22T01:18:03+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:03 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:03 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:03 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:18:05 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:18:05 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:05 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:18:05 volumio-ap3 volumio[934]: (node:934) 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: 31566) Jan 22 01:18:05 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 22 01:18:05 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:06 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:06 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:06 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:06 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93840. Jan 22 01:18:06 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:06 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: Librespot-go daemon starting... Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:06+09:00" level=info msg="generated new device id: 4dc0f5de9a2d611266936833ae1ebabdd782b956" Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:06+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:06+09: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]" Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:06+09: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]" Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:06+09: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]" Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:06+09:00" level=debug msg="zeroconf server listening on port 40673" Jan 22 01:18:06 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:06+09:00" level=debug msg="obtained new client token: AACeqBp7pJmo4+R9jKTrn1rYbigMuYLWsv3v8X2MWNGOLjQxUT9z0ec6FFBfP94/P/RqFtFC0LA208HlFhAAqjvbRzP76RNVixPgb9oVDyigvjR8NQxpDdh5msWwvhG2Em+mzMQghuYIbzIZz6yUSIaPx2UkOos58mqcsn3flXhg7XQdg6cTrr5a0oH53+6+1vM1UjHFI8sL0r/KG+bTHC1l2X21D7jBnEBBLz3+lEileBcuXfhj2KKjioHKMKvs" Jan 22 01:18:07 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:07+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:07 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:07+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:07 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:07+09:00" level=debug msg="completed challenge" Jan 22 01:18:07 volumio-ap3 go-librespot[5744]: time="2025-01-22T01:18:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:09 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:09 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93841. Jan 22 01:18:11 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:11 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: Librespot-go daemon starting... Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09:00" level=info msg="generated new device id: 937df1b67ee661aba2a9f1abf38ed9dcf6a69e39" Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09: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]" Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09: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]" Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09: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]" Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09:00" level=debug msg="zeroconf server listening on port 39327" Jan 22 01:18:11 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:18:11 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:18:11 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:18:11 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:11 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09:00" level=debug msg="obtained new client token: AADELuZr02RfHadHbuuYOH8aBaikPdTBrflVwS8+t/AAugPYcC3bNfCGFNZ6EQtjXTbomdUQxaft1robbJ5fJdXk/dlBU7u0/xwTFJzU6HAd3FWwd/+LnkJ5FUqTaQsS2ejcMxvuiI1qizgOaCNDiH04dwRr8nnXDZPGOqPZufVDxRGzEgVcv0l5IgMUAn4177LqraXH/Jsh3KGb7Sf+2rU/vGejXFUPm0GfG2Pw+/+ck0ecKCXn4UsBL4YR9TmB" Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:11 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:11+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:12 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:12+09:00" level=debug msg="completed challenge" Jan 22 01:18:12 volumio-ap3 go-librespot[5775]: time="2025-01-22T01:18:12+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:12 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:12 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:12 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:12 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:12 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to 192.168.1.144 from 192.168.1.116 UA: Mozilla/5.0 (Linux; Android 12; SM-G977N Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetVisibleSources Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetQueue Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreStateMachine::getQueue Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CorePlayQueue::getQueue Jan 22 01:18:12 volumio-ap3 volumio[934]: info: Listing playlists Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 22 01:18:12 volumio-ap3 volumio[934]: info: Received Get System Info Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:18:12 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:18:12 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:13 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 22 01:18:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93842. Jan 22 01:18:15 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:15 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: Librespot-go daemon starting... Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09:00" level=info msg="generated new device id: d1371b0ed050a174a9653307620fab143e24f520" Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:15 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09:00" level=debug msg="new websocket client" Jan 22 01:18:15 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09: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]" Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09: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]" Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09: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]" Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09:00" level=debug msg="zeroconf server listening on port 36245" Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09:00" level=debug msg="obtained new client token: AAA651tUmTdAtA/njZOjGAT4lICGt8D+kduvQHhees9p8PlqpWRynPn/rgwai152fCWMOam/ZZQax7wDwHx9YMjEr+KdNRlY13BF06wB9LQiKGqr8ZCKrrj1u0CW+w9+L6KNUUZ0PdXuGi/79lNOcpKYttU/3NE9OBRVB3KgUfj4qqoS+8CCk2mAIWf4/lB/3p6XMtNdA1xfXSA4HJge5GqoU2v9PTNpXsLa5MrppufsMl/LtOJoeDAnV+YYhqTH" Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:15 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:15+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:16 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:16+09:00" level=debug msg="completed challenge" Jan 22 01:18:16 volumio-ap3 go-librespot[5795]: time="2025-01-22T01:18:16+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:16 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:16 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:16 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:18:18 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:18:18 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:18 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:18:18 volumio-ap3 volumio[934]: (node:934) 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: 31567) Jan 22 01:18:18 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 22 01:18:18 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:19 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:19 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93843. Jan 22 01:18:19 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:19 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: Librespot-go daemon starting... Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:19+09:00" level=info msg="generated new device id: 99d4e0a3f2443230cb454502e7f729a7b806e25e" Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:19+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:19+09: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]" Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:19+09: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]" Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:19+09: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]" Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:19+09:00" level=debug msg="zeroconf server listening on port 44577" Jan 22 01:18:19 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:19+09:00" level=debug msg="obtained new client token: AAAfcK/8UHpx/FOdsv0yOw2MhC94FXQIcZjUg204KyHp99pVO/Y7Ooijv68I7CTU3utg/jJd6rztizIoj7+GL/6MsDM4xdO7ZG6A36ZgagDNO0UFF0NU+Yt/bpPQIZnrWuuGvk5YdUpdQF2ld6yz4A8R8RNXIszTh1T2jry6bV7Tr4kOllSW6Y1/f5eQ41q6MyLcFgwl9qrxZtDjZy4OETNypQOKGxcSuNqvySDDC2qbVrK3wr9NrJSiYK2ThAD3" Jan 22 01:18:20 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:20+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:20 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:20+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:20 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:20+09:00" level=debug msg="completed challenge" Jan 22 01:18:20 volumio-ap3 go-librespot[5828]: time="2025-01-22T01:18:20+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:20 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:20 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:22 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:22 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:23 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:23 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93844. Jan 22 01:18:23 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:23 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:23 volumio-ap3 go-librespot[5847]: Librespot-go daemon starting... Jan 22 01:18:23 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:23+09:00" level=info msg="generated new device id: a0198ce364d839e058f07e897acbe72eefe47293" Jan 22 01:18:23 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:23+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09: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]" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09: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]" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09: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]" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09:00" level=debug msg="zeroconf server listening on port 36431" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09:00" level=debug msg="obtained new client token: AAA+Iei2rr/2u51h3u4fonevKD71wPWZ/4UF6gpH7w66rlWyDbkxJCWfEHZfs9MwA6ER/aGAIKVjqiLpgf1kyb7gFxrxTwWSxx/Js/KoQnKKvdGAuSGKvNAygfZTXuMu2dQmLbaL4MQPEBxe6CV4riuW7m+/+CKOL9wObLR66sBCuis57lpFpDp+TzEglS52Tibm1IcZB6OZYttkH296n426YOoKhd/18yRY+HCvn+Y/sqOhziAlSgsFZWiqXg==" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09:00" level=debug msg="completed challenge" Jan 22 01:18:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:18:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:18:24 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:18:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:18:24 volumio-ap3 go-librespot[5847]: time="2025-01-22T01:18:24+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:25 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:25 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:26 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::ClearQueue Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::stop Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::stPlaybackTimer Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::updateTrackBlock Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrackBlock Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::pushState Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPushState Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::serviceStop Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::serviceStop Jan 22 01:18:26 volumio-ap3 volumio[934]: info: [1737476306515] ControllerWebradio::stop Jan 22 01:18:26 volumio-ap3 volumio[934]: verbose: ControllerMpd::sendMpdCommand stop Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::clearPlayQueue Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::saveQueue Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPushQueue Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::addQueueItems Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::addQueueItems Jan 22 01:18:26 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:18:26 volumio-ap3 volumio[934]: info: Adding Item to queue: https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8 Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPushQueue Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::saveQueue Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::updateTrackBlock Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrackBlock Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPlay Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::play index 0 Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::stop Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::play index undefined Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CoreStateMachine::startPlaybackTimer Jan 22 01:18:26 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:26 volumio-ap3 volumio[934]: info: [1737476306525] ControllerWebradio::clearAddPlayTrack Jan 22 01:18:26 volumio-ap3 volumio[934]: verbose: ControllerMpd::sendMpdCommand stop Jan 22 01:18:28 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:28 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93845. Jan 22 01:18:28 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:28 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: Librespot-go daemon starting... Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09:00" level=info msg="generated new device id: 3bef96ddfaa13761e94537213dba3429c9a9f0b5" Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09: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]" Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09: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]" Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09: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]" Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09:00" level=debug msg="zeroconf server listening on port 36091" Jan 22 01:18:28 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09:00" level=debug msg="new websocket client" Jan 22 01:18:28 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09:00" level=debug msg="obtained new client token: AAAYI18illSy1tiZ64msHyqBe4kRUN289oXZy7a5t7IYOSrPlb7+iSAORSBev7t+R2zWt+XrqmU0Y4/41KD3hcJf6ptyUsl1vXCX01+DwQGMjA1nKO145+MjD6UwC0zeejTA4d8oBisfWPOhOCN/j3zAb62THYHqMQAIbjXXZUXKTB2PfgBqzwZYHALyhhHrVkZIzt4PqzoYLXnrThjNMqhDp9CR2SF9shOk0RCiI6NKeVL2izXJ+teftofwsXSt" Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:28 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:28+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:29 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:29+09:00" level=debug msg="completed challenge" Jan 22 01:18:29 volumio-ap3 go-librespot[5874]: time="2025-01-22T01:18:29+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:29 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:29 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:29 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:18:31 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:18:31 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:31 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:18:31 volumio-ap3 volumio[934]: (node:934) 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: 31568) Jan 22 01:18:31 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 22 01:18:31 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:31 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:32 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::ClearQueue Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::stop Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CorePlayQueue::clearPlayQueue Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CorePlayQueue::saveQueue Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPushQueue Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::addQueueItems Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CorePlayQueue::addQueueItems Jan 22 01:18:32 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:18:32 volumio-ap3 volumio[934]: info: Adding Item to queue: https://m-aac.cbs.co.kr/mweb_cbs939/_definst_/cbs939.stream/playlist.m3u8 Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPushQueue Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CorePlayQueue::saveQueue Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::updateTrackBlock Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrackBlock Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPlay Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::play index 0 Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::stop Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::play index undefined Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CoreStateMachine::startPlaybackTimer Jan 22 01:18:32 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:32 volumio-ap3 volumio[934]: info: [1737476312120] ControllerWebradio::clearAddPlayTrack Jan 22 01:18:32 volumio-ap3 volumio[934]: verbose: ControllerMpd::sendMpdCommand stop Jan 22 01:18:32 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:32 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:32 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:32 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93846. Jan 22 01:18:32 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:32 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: Librespot-go daemon starting... Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09:00" level=info msg="generated new device id: a1f9ba9a9d15c7c3d2b580d00a0d949a3443bbc8" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09: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]" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09: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]" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09: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]" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09:00" level=debug msg="zeroconf server listening on port 42363" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09:00" level=debug msg="obtained new client token: AACpwyf7+uFVoCkWsCeqmB51ZEFeYu192Z9kjPjJ4FW1UvLIwpVAgUGubsq46N9gmIvcN0lBROO8QHctsTGEiQjgnhbQsHtV/Xm0JyMoJotESmkzATar1vajRm8Co00vLPZV5DArD2llCo/1n8DRZMfKdRTuRGw2Ncy/BkqQKSSav1z8Gva125ku9laaoflUcihWRj9iJOkZkVw+tmi7NpZUdBAYbfTKmSJml+Rg8cXPkORQsOWyYq6PHFvim+XI" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:32 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:32+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:33 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:33+09:00" level=debug msg="completed challenge" Jan 22 01:18:33 volumio-ap3 go-librespot[5882]: time="2025-01-22T01:18:33+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:33 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:33 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:34 volumio-ap3 systemd[1]: Stopping Music Player Daemon... Jan 22 01:18:35 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:35 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:36 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:36 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93847. Jan 22 01:18:36 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:36 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: Librespot-go daemon starting... Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:36+09:00" level=info msg="generated new device id: 621a61206d65f83bc8db6d727e30fb860f5e3726" Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:36+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:36+09: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]" Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:36+09: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]" Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:36+09: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]" Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:36+09:00" level=debug msg="zeroconf server listening on port 38067" Jan 22 01:18:36 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:36+09:00" level=debug msg="obtained new client token: AAAr7SD5Kw4khrFZx44KMdALdRGCxzVdzsS2HLAGqrsPFk0SK5fbvXXGUERTthHELRbK0lneMtlWsgPMcUtdgTJ1sfnWti605kG7ydpWUOs9VhDl7KSRX+QkwEbKMRWhtM4UYKbX7qklrod1qqWd9gSzgUXU8vj+tCIFMI6fEgw17rNY40vZ4gZI8HCB4wENk+50CUsD5cvUv8WYtflepeebB8iM9oXvWhA9m0hRo0OzahaoqSqvyOvO/GVpwnoj" Jan 22 01:18:37 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:37+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:37 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:37+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:37 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:37+09:00" level=debug msg="completed challenge" Jan 22 01:18:37 volumio-ap3 go-librespot[5895]: time="2025-01-22T01:18:37+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:37 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:37 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:38 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:38 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:39 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::ClearQueue Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::stop Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CorePlayQueue::clearPlayQueue Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CorePlayQueue::saveQueue Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPushQueue Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::addQueueItems Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CorePlayQueue::addQueueItems Jan 22 01:18:39 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:18:39 volumio-ap3 volumio[934]: info: Adding Item to queue: https://edge1.sr.se/p2-flac Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPushQueue Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CorePlayQueue::saveQueue Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::updateTrackBlock Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrackBlock Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPlay Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::play index 0 Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::stop Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::play index undefined Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CoreStateMachine::startPlaybackTimer Jan 22 01:18:39 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:39 volumio-ap3 volumio[934]: info: [1737476319019] ControllerWebradio::clearAddPlayTrack Jan 22 01:18:39 volumio-ap3 volumio[934]: verbose: ControllerMpd::sendMpdCommand stop Jan 22 01:18:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93848. Jan 22 01:18:40 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:40 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:40 volumio-ap3 go-librespot[5917]: Librespot-go daemon starting... Jan 22 01:18:40 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:40+09:00" level=info msg="generated new device id: fc98c2bfac09ff675eead9b83d6eb4e9ae0003ba" Jan 22 01:18:40 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:40+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09: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]" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09: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]" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09: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]" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09:00" level=debug msg="zeroconf server listening on port 35243" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09:00" level=debug msg="obtained new client token: AAA9QrVcp70ZhkzyzUzEUVaMWsYSrdzoD1nwFnri7v6GAT0Ou+LBtbi+xKNloOv8XnKBX6NCEsZh3szu8l5wpxHWYSazINCvE2L+nvk9CpzspTY4FM33nz5u2VhqZaD+dGTERQescB0uJJLvrAO4MGW/oQ9QuQ8MHRmi3L4oFoeOBZiFZo31CQQDKfLN6jfJqDr6Oof511G97BvQFs3w/vIrBNQIR0kTp6lLKrIyg6C9m6IzwbzWQqpMjga7mw==" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:41 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09:00" level=debug msg="new websocket client" Jan 22 01:18:41 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09:00" level=debug msg="completed challenge" Jan 22 01:18:41 volumio-ap3 go-librespot[5917]: time="2025-01-22T01:18:41+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:41 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:41 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:41 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:18:44 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:18:44 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:44 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:18:44 volumio-ap3 volumio[934]: (node:934) 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: 31569) Jan 22 01:18:44 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 22 01:18:44 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:44 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:44 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:44 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:45 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:45 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93849. Jan 22 01:18:45 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:45 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: Librespot-go daemon starting... Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09:00" level=info msg="generated new device id: b67e204983375ad73c8b8eaa93bd087a9d78bf92" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09: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]" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09: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]" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09: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]" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09:00" level=debug msg="zeroconf server listening on port 38589" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09:00" level=debug msg="obtained new client token: AACB7Blf8g4P0KQEXrxe++ZjKEGx3GeQz3Q9ZuPJeLgi7mzxlSt4h4uCtqyJOBhwehkM1xBF2rOvhOCm+Yu5A32MCCbs58J56Ozc6zCeBElQPeJ23fsd1QiQsUKgwZmip+9/qkqoOAIGfg1bmomHHOO/1oY3HKbaht1rwNBa+66FdSCjurmfEkwa95RC2DJ9sspcWY9Odd2BD/xR05b6zYtikUyvLdyA8fTPzUOOBF32FukEzSU0YgNc8Kxar2fW" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:45 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:45+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:46 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:46+09:00" level=debug msg="completed challenge" Jan 22 01:18:46 volumio-ap3 go-librespot[5929]: time="2025-01-22T01:18:46+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:46 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:46 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:47 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:47 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:49 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:49 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93850. Jan 22 01:18:49 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:49 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: Librespot-go daemon starting... Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09:00" level=info msg="generated new device id: 932242bdb17fb617bd355e29a38ddefe223e97f0" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09: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]" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09: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]" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09: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]" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09:00" level=debug msg="zeroconf server listening on port 41779" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09:00" level=debug msg="obtained new client token: AABUGL/oMk00tLRvFn5DlhMoiOjAj9FkJFtiCbRV7P1mC31NdZavY9IB/qPB9t8/vXAKOHVTktHoAxzvGW+BwFTiP/krKP4Vfw9MCUYMntVsIiXWc75OXZoi0sYCDbTvnH8I/sg1ipzqTItJ2LGz8DK7NgkzIHYw6/YdAFIXoMCMCQUFSfBnOOqoKfsNqeNcA9QfArEZTmd1K6Wt/rbaZIRGPCUAApqiepPf/U7ub8HrdifcFI22rDrzVvRBb1F3" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:49 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:49+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:50 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:50+09:00" level=debug msg="completed challenge" Jan 22 01:18:50 volumio-ap3 go-librespot[5989]: time="2025-01-22T01:18:50+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:50 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:50 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:50 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:50 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:53 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPlay Jan 22 01:18:53 volumio-ap3 volumio[934]: info: CoreStateMachine::play index undefined Jan 22 01:18:53 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:53 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:53 volumio-ap3 volumio[934]: info: CoreStateMachine::startPlaybackTimer Jan 22 01:18:53 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:53 volumio-ap3 volumio[934]: info: [1737476333188] ControllerWebradio::clearAddPlayTrack Jan 22 01:18:53 volumio-ap3 volumio[934]: verbose: ControllerMpd::sendMpdCommand stop Jan 22 01:18:53 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:53 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93851. Jan 22 01:18:53 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:53 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: Librespot-go daemon starting... Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09:00" level=info msg="generated new device id: f1673827e2154f8304e22ce83b7ae40190b610a7" Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09: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]" Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09: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]" Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09: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]" Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09:00" level=debug msg="zeroconf server listening on port 45301" Jan 22 01:18:53 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09:00" level=debug msg="new websocket client" Jan 22 01:18:53 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:18:53 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:53+09:00" level=debug msg="obtained new client token: AAAEDD1XYyQVh7MO02Z9Gb1JO8GcS0xTwGLl2gVcXkxgWu7STL4Ee4dD38oAvbD61hSAHmnnk7adPRwKrXSpp/5vaXmM/1wXdPleNFdr2ykLlMl3Xh2vje5gdDIa489qyd4VvwHJtvgXpq3gyVnnaQ4fypBomDy680KQrfr5wLXXhzQQ4X7QaQej9EAGLFDSBS46LMzHJcw+GkVdcqFDmGquKwgPahaIZ89zHgTpbrOTmRc4W9CkonOAwPq2Rotq" Jan 22 01:18:54 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:54+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:54 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:54+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:54 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:54+09:00" level=debug msg="completed challenge" Jan 22 01:18:54 volumio-ap3 go-librespot[5997]: time="2025-01-22T01:18:54+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioPlay Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreStateMachine::play index undefined Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreStateMachine::startPlaybackTimer Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:54 volumio-ap3 volumio[934]: info: [1737476334659] ControllerWebradio::clearAddPlayTrack Jan 22 01:18:54 volumio-ap3 volumio[934]: verbose: ControllerMpd::sendMpdCommand stop Jan 22 01:18:54 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:18:54 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:54 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:18:54 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:54 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:18:56 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:18:56 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:56 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:18:56 volumio-ap3 volumio[934]: (node:934) 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: 31570) Jan 22 01:18:56 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 22 01:18:56 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:18:56 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:18:57 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:18:57 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:18:57 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:18:57 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93852. Jan 22 01:18:57 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:18:57 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:18:57 volumio-ap3 go-librespot[6019]: Librespot-go daemon starting... Jan 22 01:18:57 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:57+09:00" level=info msg="generated new device id: 007b0331d650e7de4c57a6e8ab0a3e17bb2c93b3" Jan 22 01:18:57 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:57+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09: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]" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09: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]" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09: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]" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09:00" level=debug msg="zeroconf server listening on port 33883" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09:00" level=debug msg="obtained new client token: AAC75ljyeGlbJFXqJ3/yjgohpGCcmu0D4nJSQR1IULXI7RB7A+infC+Lr8pxs24F6xPN09HpOxHze135gUBIQlGSB11Isxo/Ze4pZC19nhSboLESxTewg8+y3n7YOdN5rHvSIfFH2YkM08Pb0AIEydoHHIuodqPNNnhd5WBXGIejx9zlTVmNc3glIt5OAjAmp75EdM/92/jEwzr9JT7cAV8rNChnIp83z7wbBgxNpCbvU23uy0GW/WKClNyh4A==" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09:00" level=debug msg="completed keyexchange" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09:00" level=debug msg="completed challenge" Jan 22 01:18:58 volumio-ap3 go-librespot[6019]: time="2025-01-22T01:18:58+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:18:58 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:18:58 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:00 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:00 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:02 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:02 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93853. Jan 22 01:19:02 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:02 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: Librespot-go daemon starting... Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09:00" level=info msg="generated new device id: fd9128223d76c020a154781df46a261ae590e7b0" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09: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]" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09: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]" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09: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]" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09:00" level=debug msg="zeroconf server listening on port 33323" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09:00" level=debug msg="obtained new client token: AAA6brcpDs0JZcXKRD+mwgCZ+xGEkg3aT8E/qI5aWHVJoSLLWBy3MA/3hTew72Yd0u6Vy6C1/3ImE9ES1gfe7LF13IxRAdhNKhkmT+n2HrQ9sQlll0QxNNPE9MfsMcF2rAaZyJXqbsNOM+2B08J2Dp1rzF3Id4BxJMHcKVPaQsifk8IDkG0gxmZahTF088ISZmyEEAKwUQWv+YcaXx98xGBQSB/BXKCDxyogly0FCIq/S3bjaJvkXVcCt0FFMJcj" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:02 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:02+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:03 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:03+09:00" level=debug msg="completed challenge" Jan 22 01:19:03 volumio-ap3 go-librespot[6028]: time="2025-01-22T01:19:03+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:03 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:03 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:03 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:03 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:03 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 22 01:19:03 volumio-ap3 volumio[934]: info: CURURI: music-library Jan 22 01:19:06 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:06 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93854. Jan 22 01:19:06 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:06 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: Librespot-go daemon starting... Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09:00" level=info msg="generated new device id: ad9a54015b8430cb451070d0394ee99cd3e916b5" Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09: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]" Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09: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]" Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09: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]" Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09:00" level=debug msg="zeroconf server listening on port 38529" Jan 22 01:19:06 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09:00" level=debug msg="new websocket client" Jan 22 01:19:06 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09:00" level=debug msg="obtained new client token: AACLz0bPipDEq+/oIkRzxtKJ74Xxt2rqs+QH/TKSYgvpUfjKLVPUiTRMqpU7HYh4nhFUUEx66iIUnvoGmCdppGSV+UsuctVUNZnMWCRze2KMqFeE5AlPtwqXYjCjcz31guXleza79l5Q4UHEP0f/hI4LQcwIdqx0soOGlzXRYD9kqaEnyFP59YQxtuC0QfvsX61kMLEQhsgT8MdZkH832deKUfr9t2olMOEGl7/DaSpEpjc985J/q8qxPLoY3l3e" Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:06 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:06+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:07 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:07+09:00" level=debug msg="completed challenge" Jan 22 01:19:07 volumio-ap3 go-librespot[6037]: time="2025-01-22T01:19:07+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:07 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:19:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:07 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:09 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:19:09 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:09 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:19:09 volumio-ap3 volumio[934]: (node:934) 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: 31571) Jan 22 01:19:09 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 22 01:19:09 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:09 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:10 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:10 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:10 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:10 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93855. Jan 22 01:19:10 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:10 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: Librespot-go daemon starting... Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:10+09:00" level=info msg="generated new device id: 481a6e6b173d08d92cab3388f63d5cd7626ef69f" Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:10+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:10+09: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]" Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:10+09: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]" Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:10+09: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]" Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:10+09:00" level=debug msg="zeroconf server listening on port 46411" Jan 22 01:19:10 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:10+09:00" level=debug msg="obtained new client token: AABHP0bgQZSZZsJAuNm4Y6SYoTQLheqjLEKHGV1EvPLh8SOc6yzqzfvUngy8Rx/QYc6ClkKasGVLzFEfVgGfXJNQHy/arysUf0hnnCKGB+ZQH19kjL/Vj2IFch4i+/m+mJhTJIhO5ouZBOZQjh6g4f+cQP/zvFVC0wBYPQWjOf2jtv2n0Ij5xPQixuHreAqPt9hgTal3OYnEbJWqKsNJswKc5SelrIOJdISv238S6UGpyHIKODeAnflqXktK27nk" Jan 22 01:19:11 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:11+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:11 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:11+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:11 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:11+09:00" level=debug msg="completed challenge" Jan 22 01:19:11 volumio-ap3 go-librespot[6059]: time="2025-01-22T01:19:11+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:11 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:13 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:13 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:14 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:19:14 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:19:14 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:19:14 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:14 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:14 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:19:14 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:14 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93856. Jan 22 01:19:14 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:14 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:14 volumio-ap3 go-librespot[6069]: Librespot-go daemon starting... Jan 22 01:19:14 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:14+09:00" level=info msg="generated new device id: 428f661e250b6e1efe4282343525d2d176bfa8e9" Jan 22 01:19:14 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:14+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09: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]" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09: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]" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09: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]" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09:00" level=debug msg="zeroconf server listening on port 37363" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09:00" level=debug msg="obtained new client token: AAAFDBUUw55cNMPRebk4phKdmeQYTnV2j6pifZzFd+LwCb53cdJTOeVtNPQyLg8UU7j3FyoZMJ1rnYRYVuSQzzEuFcuQdJiXND9oU7ZqUcVA2XTG7dUOtPniiG0LXl8sZ/Uaz2mHrL44FrB1RGLKvjxnkbnNuM/l+VYQL1KxNGA3YaRjVxia0Nsr8NK+vmjP8v94ZocOEaAwARrF5Bn6bCFL4qghr4+SBDMwx4eVrrbG716lbRFSwtiIp7XT+Q==" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09:00" level=debug msg="completed challenge" Jan 22 01:19:15 volumio-ap3 go-librespot[6069]: time="2025-01-22T01:19:15+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:15 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:16 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:16 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:19 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93857. Jan 22 01:19:19 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:19 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: Librespot-go daemon starting... Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09:00" level=info msg="generated new device id: fe761f206b9be28febb026350ac84053981670f6" Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09: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]" Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09: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]" Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09: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]" Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09:00" level=debug msg="zeroconf server listening on port 41107" Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09:00" level=debug msg="obtained new client token: AABh6d3SF2p8377ThYHp7T4JY24ri+Pp0FUBefNq4KW48fqmV25u6OQIatpaQL6lxsHAW8yBqjHBFyt+hqHemz1fqN1Pm11qmYSk0nUsLPsQ+T5bfvDyleBG0Q/59R7lC47oHu885OdSSH9gyaqLXXYvSkzrfWhlyQQ5ir/ygtSjA5rf0cX4G3B55fL8B50ihZmIW2Xlx5Tt2OW2n8wBcP7/xYZc4OWcn7luLxuJ7FZtg4YwxR+nRIHRMbDzcl5p" Jan 22 01:19:19 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09:00" level=debug msg="new websocket client" Jan 22 01:19:19 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:19 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:19+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:20 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:20+09:00" level=debug msg="completed challenge" Jan 22 01:19:20 volumio-ap3 go-librespot[6091]: time="2025-01-22T01:19:20+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:20 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:20 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:20 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:19:22 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:19:22 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:22 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:19:22 volumio-ap3 volumio[934]: (node:934) 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: 31572) Jan 22 01:19:22 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:19:22 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:19:22 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to 192.168.1.144:3000 from 192.168.1.116 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 22 01:19:22 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 22 01:19:23 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:23 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:23 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:23 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93858. Jan 22 01:19:23 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:23 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: Librespot-go daemon starting... Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09:00" level=info msg="generated new device id: 8bc5ac3e4770f73eddb8c3e1780524beeb8cd3c7" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09: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]" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09: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]" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09: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]" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09:00" level=debug msg="zeroconf server listening on port 41397" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09:00" level=debug msg="obtained new client token: AAA09vNR1G2UE/rcDGsPDf9DkwiWx6NyxaznEIgvlKt1l/ltJZs0Kvk4JibF+ao9ztjf84mtU+OExtXHTeDCrBb0BMHVs4HZqp6SdtdO2SrB/GnKJYMyHH9LTkTMbEcEuEhEXWoRmcrdFVY5+lMNXok1/0+zyKZDumeP6dWjILdvOMq7H/zFXH9AvLR1g7bkvfzOx3Rt36G2M5O9OTItsqJmXWH4b4NHH5SOuO8Yd2S1IMfajIYe3AtUfs11juyc" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:23 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:23+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:24 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:24+09:00" level=debug msg="completed challenge" Jan 22 01:19:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:19:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:19:24 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:19:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:24 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:24 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:19:24 volumio-ap3 go-librespot[6099]: time="2025-01-22T01:19:24+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:24 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:26 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:26 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:27 volumio-ap3 sudo[6109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 22 01:19:27 volumio-ap3 sudo[6109]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 22 01:19:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:27 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93859. Jan 22 01:19:27 volumio-ap3 sudo[6109]: pam_unix(sudo:session): session closed for user root Jan 22 01:19:27 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:27 volumio-ap3 sudo[6112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 22 01:19:27 volumio-ap3 sudo[6112]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 22 01:19:27 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:27 volumio-ap3 sudo[6112]: pam_unix(sudo:session): session closed for user root Jan 22 01:19:27 volumio-ap3 go-librespot[6113]: Librespot-go daemon starting... Jan 22 01:19:27 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:27+09:00" level=info msg="generated new device id: a6d89b8be1c28d3db3212bfe2e7424dea036ddbf" Jan 22 01:19:27 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:27+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:27 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to 192.168.1.144 from 192.168.1.116 UA: Mozilla/5.0 (Linux; Android 12; SM-G977N Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jan 22 01:19:27 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:27+09: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]" Jan 22 01:19:27 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:27+09: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]" Jan 22 01:19:27 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:27+09: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]" Jan 22 01:19:27 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:27+09:00" level=debug msg="zeroconf server listening on port 42297" Jan 22 01:19:28 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:28+09:00" level=debug msg="obtained new client token: AABjeGklEVj6Gtwitd7x9Cn6zDkGDlq1/yjVISwW1LAynpu/KK6l/DOvsa+fo+wo4SXe90iTCmSTIgdb+D0DM9C4vWAPeINfauPdw2t1gBqw3OYuz7qc+kmFETEz+1XDA46y2kW5kjW3BymN1asXi+Cy3MavjU/IgIVJSdcHXlX2891dQqPJ0gDsa1emuB7bUD9mf1JoCbIMkLiX+k99iJCFErJPwocjW+fA8orAk2pa6rXh45EnvpDiAS57nQ==" Jan 22 01:19:28 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:28+09:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070 (error: dial tcp 104.199.241.202:4070: connect: connection refused), retrying with a different AP" Jan 22 01:19:28 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:28+09:00" level=info msg="connected to ap-gae2.spotify.com:443" Jan 22 01:19:28 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:28+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:28 volumio-ap3 sudo[6137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 22 01:19:28 volumio-ap3 sudo[6137]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 22 01:19:28 volumio-ap3 sudo[6137]: pam_unix(sudo:session): session closed for user root Jan 22 01:19:28 volumio-ap3 sudo[6140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 22 01:19:28 volumio-ap3 sudo[6140]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 22 01:19:28 volumio-ap3 sudo[6140]: pam_unix(sudo:session): session closed for user root Jan 22 01:19:28 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to 192.168.1.144 from 192.168.1.116 UA: Mozilla/5.0 (Linux; Android 12; SM-G977N Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.260 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 22 01:19:28 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:28+09:00" level=debug msg="completed challenge" Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetVisibleSources Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetQueue Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreStateMachine::getQueue Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CorePlayQueue::getQueue Jan 22 01:19:28 volumio-ap3 volumio[934]: info: Listing playlists Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 22 01:19:28 volumio-ap3 volumio[934]: info: Received Get System Info Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:19:28 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 22 01:19:28 volumio-ap3 go-librespot[6113]: time="2025-01-22T01:19:28+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:28 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:28 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:28 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 22 01:19:29 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:29 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:30 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 22 01:19:30 volumio-ap3 volumio[934]: info: Received Get System Info Jan 22 01:19:30 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:19:30 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:19:30 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:19:30 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:30 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:30 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:19:30 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 22 01:19:31 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 22 01:19:31 volumio-ap3 volumio[934]: info: Received Get System Info Jan 22 01:19:31 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 22 01:19:31 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 22 01:19:31 volumio-ap3 volumio[934]: info: Discovery: Getting this device information Jan 22 01:19:31 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:31 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:31 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 22 01:19:32 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:32 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93860. Jan 22 01:19:32 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:32 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: Librespot-go daemon starting... Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09:00" level=info msg="generated new device id: cae52885832b3dbaf9fce8cc4a0999f9f708067b" Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:32 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09:00" level=debug msg="new websocket client" Jan 22 01:19:32 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket established Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09: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]" Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09: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]" Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09: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]" Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09:00" level=debug msg="zeroconf server listening on port 35637" Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09:00" level=debug msg="obtained new client token: AACCvGelj13+ofROAOKgireY04flW0WC+8Fu9HTKR0mMbqk75aK04Axqpt/CfeG7rLRnnXhdHIoDxotXCwMyYHmxTiA7N5H1oc8S/8ikWzpnBUjj9gOtWzuxnUZv1rvXGqiX1+BZDRgp3m3fFZAsI0ZYjBaqKwM/5Jq3HXgCdvz//rgw6ddFG/kAJdpqv2qfEiV+dH0oJacjAB70WmhBd7Aa4MupcH6qgaf/MhSKqgduwF34iP9uBeq+0zOBlH7D" Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:32 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:32+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:33 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:33+09:00" level=debug msg="completed challenge" Jan 22 01:19:33 volumio-ap3 go-librespot[6142]: time="2025-01-22T01:19:33+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:33 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:33 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:33 volumio-ap3 volumio[934]: info: Connection to go-librespot Websocket closed Jan 22 01:19:34 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 22 01:19:34 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:19:35 volumio-ap3 volumio[934]: info: Getting Spotify volume Jan 22 01:19:35 volumio-ap3 volumio[934]: (node:934) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:35 volumio-ap3 volumio[934]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 22 01:19:35 volumio-ap3 volumio[934]: (node:934) 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: 31573) Jan 22 01:19:35 volumio-ap3 volumio[934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 22 01:19:35 volumio-ap3 volumio[934]: info: CoreCommandRouter::volumioGetState Jan 22 01:19:35 volumio-ap3 volumio[934]: info: CorePlayQueue::getTrack 0 Jan 22 01:19:35 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 22 01:19:35 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:19:36 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:36 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:36 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:36 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93861. Jan 22 01:19:36 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:36 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: Librespot-go daemon starting... Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09:00" level=info msg="generated new device id: 57709ad121ec48adfc60178c84c9dfe8083a5fd9" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09: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]" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09: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]" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09: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]" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09:00" level=debug msg="zeroconf server listening on port 38453" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09:00" level=debug msg="obtained new client token: AACBgRf+vzmGC1tE+LTn3FkLQLMEQR7pnPZfvmAmg22qubhlXjTm5tmpYtj3SbUxf9u99uxcjhvoemz1GC5++xVKb6LYlJEEf2Tb947Hg29hJxl3X0drDGKl13y6rOVqx7anH9s7QFkWoEmnA0J+hNcsaku6VIlRLAynwViR+zNNjZp1IRdDMtIPb/0EX4+/qbKIfkBR8Eg1r/RVLBFRFkf68Cw57R3CL0aEXqEfoyXoF8QcdBkvvtsNUdgSisin" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:36 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:36+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:37 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 22 01:19:37 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:19:37 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:37+09:00" level=debug msg="completed challenge" Jan 22 01:19:37 volumio-ap3 go-librespot[6150]: time="2025-01-22T01:19:37+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:37 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:37 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:38 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 22 01:19:38 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 22 01:19:38 volumio-ap3 volumio[934]: info: Preload queue cleared Jan 22 01:19:39 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:39 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 22 01:19:40 volumio-ap3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93862. Jan 22 01:19:40 volumio-ap3 systemd[1]: Stopped go-librespot Daemon. Jan 22 01:19:40 volumio-ap3 systemd[1]: Started go-librespot Daemon. Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: Librespot-go daemon starting... Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:40+09:00" level=info msg="generated new device id: 8305e1c901c155ca5a0ec1b97fb39b4d3e293bb3" Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:40+09:00" level=debug msg="stored credentials found for 0p5pdobhwlkcud2dbj5tj8jsj" Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:40+09: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]" Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:40+09: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]" Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:40+09: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]" Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:40+09:00" level=debug msg="zeroconf server listening on port 35737" Jan 22 01:19:40 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:40+09:00" level=debug msg="obtained new client token: AAAwhbK274oBCcTy8g6SQsPVSniHjAqNKmEr/tS0pObjzkbcKYY2108qUKq0VFMex7rf1RGONryrXsniqdaQT1L+G2Gq7mFSIqsQX0rQJJ5RFISKJXNSpc8grFeqCrQ7Wf5OmnPvlDaIniJzmWaR0YNgaBsNiJsZqh/pVH0poyydkky+O35qdCxAMCgeN6EPlXfrB43JXjoUDAakFCJogICECDic0eKQJI2U11gZfbzC6EIb1POOwhxll2UfHvp1" Jan 22 01:19:41 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:41+09:00" level=info msg="connected to ap-gae2.spotify.com:4070" Jan 22 01:19:41 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:41+09:00" level=debug msg="completed keyexchange" Jan 22 01:19:41 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:41+09:00" level=debug msg="completed challenge" Jan 22 01:19:41 volumio-ap3 go-librespot[6172]: time="2025-01-22T01:19:41+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jan 22 01:19:41 volumio-ap3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 22 01:19:41 volumio-ap3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 22 01:19:42 volumio-ap3 volumio[934]: info: Initializing connection to go-librespot Websocket Jan 22 01:19:42 volumio-ap3 volumio[934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 22 01:19:42 volumio-ap3 volumio[934]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 22 01:19:42 volumio-ap3 volumio[934]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 22 01:19:42 volumio-ap3 volumio[934]: TypeError: Cannot read property 'length' of undefined Jan 22 01:19:42 volumio-ap3 volumio[934]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jan 22 01:19:42 volumio-ap3 volumio[934]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jan 22 01:19:42 volumio-ap3 volumio[934]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jan 22 01:19:42 volumio-ap3 volumio[934]: at Parser.emit (events.js:315:20) Jan 22 01:19:42 volumio-ap3 volumio[934]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jan 22 01:19:42 volumio-ap3 volumio[934]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jan 22 01:19:42 volumio-ap3 volumio[934]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jan 22 01:19:42 volumio-ap3 volumio[934]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jan 22 01:19:42 volumio-ap3 volumio[934]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jan 22 01:19:42 volumio-ap3 volumio[934]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jan 22 01:19:42 volumio-ap3 volumio[934]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jan 22 01:19:42 volumio-ap3 volumio[934]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jan 22 01:19:42 volumio-ap3 volumio[934]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jan 22 01:19:42 volumio-ap3 volumio[934]: at IncomingMessage.emit (events.js:327:22) Jan 22 01:19:42 volumio-ap3 volumio[934]: at endReadableNT (internal/streams/readable.js:1327:12) Jan 22 01:19:42 volumio-ap3 volumio[934]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jan 22 01:19:42 volumio-ap3 volumio[934]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 22 01:19:43 volumio-ap3 sudo[6193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-22 01:18 Jan 22 01:19:43 volumio-ap3 sudo[6193]: 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="cc0042a1eab1cb7982711a1347e242f8947b54b6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="d316d397153fbb98c246d670c12f98a120b995a2" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 11 Jan 2025 10:58:50 AM CET" VOLUMIO_VERSION="3.788" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e6f1869148b01453dc48d3e2d79d1421"