-- Logs begin at Thu 2019-02-14 19:11:59 KST, end at Tue 2024-04-23 14:58:49 KST. -- Apr 23 14:57:01 volumio volumio[864]: info: CoreCommandRouter::Close All Modals sent Apr 23 14:57:12 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 10 Apr 23 14:57:12 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 11 Apr 23 14:57:12 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:13 volumio volumio[864]: info: peppy_screensaver: Start PeppyMeter Apr 23 14:57:24 volumio volumio[864]: info: Enabling plugin peppy_screensaver Apr 23 14:57:24 volumio volumio[864]: info: Loading plugin "peppy_screensaver"... Apr 23 14:57:24 volumio volumio[864]: info: Applying required configuration parameters for plugin peppy_screensaver Apr 23 14:57:24 volumio volumio[864]: info: Preparing to generate the ALSA configuration file Apr 23 14:57:24 volumio volumio[864]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 23 14:57:24 volumio volumio[864]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Apr 23 14:57:24 volumio volumio[864]: info: Reading ALSA contributions from plugins. Apr 23 14:57:24 volumio volumio[864]: info: Asound.conf file written Apr 23 14:57:24 volumio sudo[4861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 23 14:57:24 volumio sudo[4861]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:24 volumio sudo[4861]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:24 volumio volumio[864]: info: Output device has changed, restarting MPD Apr 23 14:57:24 volumio sudo[4867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 23 14:57:24 volumio volumio[864]: info: Output device has changed, restarting Shairport Sync Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 14:57:24 volumio sudo[4867]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:24 volumio sudo[4867]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:24 volumio sudo[4869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 23 14:57:24 volumio sudo[4869]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:24 volumio systemd[1]: Stopping Music Player Daemon... Apr 23 14:57:24 volumio volumio[864]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 14:57:24 volumio volumio[864]: info: PLUGIN START: peppy_screensaver Apr 23 14:57:24 volumio volumio[864]: info: Loading i18n strings for locale ko Apr 23 14:57:24 volumio systemd[1]: mpd.service: Succeeded. Apr 23 14:57:24 volumio systemd[1]: Stopped Music Player Daemon. Apr 23 14:57:24 volumio volumio[864]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Apr 23 14:57:24 volumio volumio[864]: error: ir_controller: Fetching language file: Error: i18n file complementing the system language not found. Apr 23 14:57:24 volumio volumio[864]: info: /tmp/myfifo created Apr 23 14:57:24 volumio systemd[1]: Starting Music Player Daemon... Apr 23 14:57:24 volumio sudo[4879]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 Apr 23 14:57:24 volumio sudo[4879]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:24 volumio sudo[4879]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:24 volumio volumio[864]: info: snd-dummy loaded Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 14:57:24 volumio sudo[4885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/shairport-sync.conf.tmpl /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl Apr 23 14:57:24 volumio sudo[4885]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:24 volumio sudo[4885]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:24 volumio volumio[864]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 14:57:24 volumio volumio[864]: info: Done. Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:24 volumio volumio[864]: info: MPD Permissions set Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Apr 23 14:57:24 volumio volumio[864]: info: Creating Spotify config file Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:24 volumio volumio[864]: info: Spotify config file written Apr 23 14:57:24 volumio volumio[864]: info: Starting Shairport Sync Apr 23 14:57:24 volumio volumio[864]: info: Starting Shairport Sync Apr 23 14:57:24 volumio sudo[4895]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 23 14:57:24 volumio sudo[4895]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:24 volumio sudo[4897]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 14:57:24 volumio sudo[4897]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:24 volumio systemd[1]: Stopping go-librespot Daemon... Apr 23 14:57:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Apr 23 14:57:24 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Apr 23 14:57:24 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 23 14:57:24 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Apr 23 14:57:24 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Apr 23 14:57:24 volumio volumio[864]: at Socket.emit (events.js:327:22) Apr 23 14:57:24 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 23 14:57:24 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 23 14:57:24 volumio volumio[864]: (node:864) 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: 97) Apr 23 14:57:24 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:57:24 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:57:24 volumio sudo[4901]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 14:57:24 volumio sudo[4901]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:57:25 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:57:25 volumio sudo[4895]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:25 volumio go-librespot[4902]: Librespot-go daemon starting... Apr 23 14:57:25 volumio go-librespot[4902]: time="2024-04-23T14:57:25+09:00" level=info msg="generated new device id: 2cb2fad0ad6cf9a030c269c2784a3e104aec0266" Apr 23 14:57:25 volumio go-librespot[4902]: time="2024-04-23T14:57:25+09:00" level=debug msg="stored credentials not found" Apr 23 14:57:25 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 23 14:57:25 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 23 14:57:25 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 23 14:57:25 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 23 14:57:25 volumio sudo[4901]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:25 volumio sudo[4897]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:25 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:25 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:57:25 volumio volumio[864]: info: Shairport-Sync Started Apr 23 14:57:25 volumio volumio[864]: info: Shairport-Sync Started Apr 23 14:57:25 volumio mpd[4875]: Apr 23 14:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 23 14:57:25 volumio systemd[1]: Started Music Player Daemon. Apr 23 14:57:25 volumio sudo[4869]: pam_unix(sudo:session): session closed for user root Apr 23 14:57:25 volumio volumio[864]: error: updateQueue error: null Apr 23 14:57:25 volumio go-librespot[4902]: time="2024-04-23T14:57:25+09:00" level=debug msg="obtained new client token: AACyQkipnFgGRsHN5gLciDrAjOsCQOcXQ37AlkMQFbFxICXWu/EiEDRtaIG7GeN9jVAlIGW2W25pivOLDiT26xcMEBFNsQWYopM/xkC6e+RqX+okocviqRV9xRKNH9Aj6h5xmcnlX1fjddLd3fEybwLD7lYeIUVlQY3y+VVHfQRS+RywPfHQ9YX4K+ZVDJMetGrxSiN/CVlvgLEOipmrbwDoA032kS+Wf+unI8yNhYWe21cuEwqUPqdFJ5+gjQ==" Apr 23 14:57:26 volumio go-librespot[4902]: time="2024-04-23T14:57:26+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]" Apr 23 14:57:26 volumio go-librespot[4902]: time="2024-04-23T14:57:26+09:00" level=debug msg="completed keyexchange" Apr 23 14:57:27 volumio go-librespot[4902]: time="2024-04-23T14:57:27+09:00" level=debug msg="completed challenge" Apr 23 14:57:27 volumio go-librespot[4902]: time="2024-04-23T14:57:27+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:57:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:57:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:57:27 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:27 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:28 volumio volumio[864]: info: go-librespot daemon successfully initialized Apr 23 14:57:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:57:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 23 14:57:30 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:57:30 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:57:30 volumio go-librespot[4916]: Librespot-go daemon starting... Apr 23 14:57:30 volumio go-librespot[4916]: time="2024-04-23T14:57:30+09:00" level=info msg="generated new device id: cf825dac961612430637d64bf9b7becfbf3097a5" Apr 23 14:57:30 volumio go-librespot[4916]: time="2024-04-23T14:57:30+09:00" level=debug msg="stored credentials not found" Apr 23 14:57:30 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:30 volumio go-librespot[4916]: time="2024-04-23T14:57:30+09:00" level=debug msg="new websocket client" Apr 23 14:57:30 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:57:31 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:31 volumio go-librespot[4916]: time="2024-04-23T14:57:31+09:00" level=debug msg="new websocket client" Apr 23 14:57:31 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:57:31 volumio go-librespot[4916]: time="2024-04-23T14:57:31+09:00" level=debug msg="obtained new client token: AAC9LysOvdit/wctd3x/MBnpGxbUe82gxbbOG3/KuOAGqJLzX5WdTdllZqNo+d+Kg5hoTU+xtz90m/jz23sS4ABJDQ+3IuP1S6NjNjqajmuCZs6JjxDXXmoL/hIEQQP8S7OmGzgqx5mPy0IX4g9k8Y6L8o5z5++FPiwz0FSkBhZ5n5ApeB3UybpiC8RX1x7qEhhoXpjlOtuIejRlpk8a605EAomIz496V93nB51w8FRaVSiHECddchFWFlyufA==" Apr 23 14:57:32 volumio go-librespot[4916]: time="2024-04-23T14:57: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 23 14:57:32 volumio go-librespot[4916]: time="2024-04-23T14:57:32+09:00" level=debug msg="completed keyexchange" Apr 23 14:57:32 volumio go-librespot[4916]: time="2024-04-23T14:57:32+09:00" level=debug msg="completed challenge" Apr 23 14:57:32 volumio go-librespot[4916]: time="2024-04-23T14:57:32+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:57:32 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:57:32 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:57:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:57:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:57:33 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:57:33 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:33 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:57:33 volumio volumio[864]: (node:864) 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: 98) Apr 23 14:57:33 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 23 14:57:34 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:34 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:57:34 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:57:34 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:34 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:57:34 volumio volumio[864]: (node:864) 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: 99) Apr 23 14:57:34 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 23 14:57:34 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:34 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:57:35 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:35 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:57:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 23 14:57:35 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:57:36 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:57:36 volumio go-librespot[4925]: Librespot-go daemon starting... Apr 23 14:57:36 volumio go-librespot[4925]: time="2024-04-23T14:57:36+09:00" level=info msg="generated new device id: aab3ccb68439214697b919ebac3c0d1f5a71e835" Apr 23 14:57:36 volumio go-librespot[4925]: time="2024-04-23T14:57:36+09:00" level=debug msg="stored credentials not found" Apr 23 14:57:36 volumio go-librespot[4925]: time="2024-04-23T14:57:36+09:00" level=debug msg="obtained new client token: AAAfFgKF0/R/OSevPU8QE5AIZEzQBieIajBJvmz4f6hlk26020dgo+uxDl7qNhWfSy+stgLTioRSpwWZ4On39nCe8pFsq/rjrONq13SHPVNSrVaz1vb1xOU02Tdqc78yr/pvc4kcN+XFCSFNX3hTbiQlKPbBt8fNOD82/xRoUNDpVhbnsls5oawBd7oN8xl2pbsL9wLFoBZit5awnWMcM5/a+q6XbZLLUqY4qqbs+BZ32ZtUrxsulpyIwbgE/g==" Apr 23 14:57:37 volumio go-librespot[4925]: time="2024-04-23T14:57:37+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]" Apr 23 14:57:37 volumio go-librespot[4925]: time="2024-04-23T14:57:37+09:00" level=debug msg="completed keyexchange" Apr 23 14:57:38 volumio go-librespot[4925]: time="2024-04-23T14:57:38+09:00" level=debug msg="completed challenge" Apr 23 14:57:38 volumio go-librespot[4925]: time="2024-04-23T14:57:38+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:57:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:57:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:57:38 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:38 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:57:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Apr 23 14:57:41 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:57:41 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:57:41 volumio go-librespot[4945]: Librespot-go daemon starting... Apr 23 14:57:41 volumio go-librespot[4945]: time="2024-04-23T14:57:41+09:00" level=info msg="generated new device id: ae064252200ca0a90a6d9a0104065e1e74b398be" Apr 23 14:57:41 volumio go-librespot[4945]: time="2024-04-23T14:57:41+09:00" level=debug msg="stored credentials not found" Apr 23 14:57:41 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:41 volumio go-librespot[4945]: time="2024-04-23T14:57:41+09:00" level=debug msg="new websocket client" Apr 23 14:57:41 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:57:42 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 10 Apr 23 14:57:42 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 11 Apr 23 14:57:42 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:42 volumio go-librespot[4945]: time="2024-04-23T14:57:42+09:00" level=debug msg="obtained new client token: AAAAipfHYd4SnkxLdaHQDkh2evkX4sgxFilNQFKT+t76f6ySNtXtxk49hX+KVO1qVtPNzkhC45WfvhRsemNuTcxJ+jDAy2CXbB9XXR7aRr/+aaWc/RLfU4s7UMchwYGeSD/fJR3JXe+5qh4sqvznQzNqknQvAaW0azK3AnzCNOgM/bHxt3QNuLNvffdxcEEBnaMQ4VvWqTsI6WCmm3Pp1ddCrxUZIHhRvp3hJZP219nezqBdASjZK4rthCZ+YA==" Apr 23 14:57:43 volumio go-librespot[4945]: time="2024-04-23T14:57:43+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]" Apr 23 14:57:43 volumio go-librespot[4945]: time="2024-04-23T14:57:43+09:00" level=debug msg="completed keyexchange" Apr 23 14:57:43 volumio ntpd[688]: Soliciting pool server 78.46.102.180 Apr 23 14:57:43 volumio go-librespot[4945]: time="2024-04-23T14:57:43+09:00" level=debug msg="completed challenge" Apr 23 14:57:43 volumio go-librespot[4945]: time="2024-04-23T14:57:43+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:57:43 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:57:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:57:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:57:44 volumio ntpd[688]: Soliciting pool server 108.59.2.24 Apr 23 14:57:44 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:57:44 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:44 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:57:44 volumio volumio[864]: (node:864) 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: 100) Apr 23 14:57:44 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 12 Apr 23 14:57:44 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:44 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:57:45 volumio ntpd[688]: Soliciting pool server 193.182.111.14 Apr 23 14:57:46 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:46 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:57:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Apr 23 14:57:46 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:57:46 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:57:46 volumio go-librespot[4969]: Librespot-go daemon starting... Apr 23 14:57:47 volumio go-librespot[4969]: time="2024-04-23T14:57:47+09:00" level=info msg="generated new device id: eac21d83680d3582c6e8d3f971b0887c2bb131e2" Apr 23 14:57:47 volumio go-librespot[4969]: time="2024-04-23T14:57:47+09:00" level=debug msg="stored credentials not found" Apr 23 14:57:47 volumio go-librespot[4969]: time="2024-04-23T14:57:47+09:00" level=debug msg="obtained new client token: AAAIpBA60gh1cee8ozEGHRphqIGfIoONlv/kNoTIEx+PVSUKQzkjtSwRn5PalIoXIsMjzSUhWBQ4tATV4xh0ng43Ezn6AZvyLc8KtGZpFg4HaWTR8bb+MWE0p+6/D79lXgbcDOXJiX+SgrIGZtKY2DBgF06wrHJO14iM+8/KHQ2oq2XQyr0nLl9MPQvRtrca27u8625NIjlljxzXTvr/55raDAdHRC6qjKP9mUv7+l/AjzzgoOlwCmR6ZNwx4A==" Apr 23 14:57:48 volumio volumio[864]: info: peppy_screensaver: Start PeppyMeter Apr 23 14:57:48 volumio go-librespot[4969]: time="2024-04-23T14:57:48+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]" Apr 23 14:57:48 volumio go-librespot[4969]: time="2024-04-23T14:57:48+09:00" level=debug msg="completed keyexchange" Apr 23 14:57:49 volumio go-librespot[4969]: time="2024-04-23T14:57:49+09:00" level=debug msg="completed challenge" Apr 23 14:57:49 volumio go-librespot[4969]: time="2024-04-23T14:57:49+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:57:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:57:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:57:49 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:49 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:57:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Apr 23 14:57:52 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:57:52 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:57:52 volumio go-librespot[4978]: Librespot-go daemon starting... Apr 23 14:57:52 volumio go-librespot[4978]: time="2024-04-23T14:57:52+09:00" level=info msg="generated new device id: 5e4baec3c994fe5f410ed4de9e398c5bb8a449bd" Apr 23 14:57:52 volumio go-librespot[4978]: time="2024-04-23T14:57:52+09:00" level=debug msg="stored credentials not found" Apr 23 14:57:52 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:52 volumio go-librespot[4978]: time="2024-04-23T14:57:52+09:00" level=debug msg="new websocket client" Apr 23 14:57:52 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:57:53 volumio go-librespot[4978]: time="2024-04-23T14:57:53+09:00" level=debug msg="obtained new client token: AAAZG+y1slVQakFZPCJrCdlU9JM1+xEbB/JiPNwYIiM6txncsamrb3ZjtoNf5rH8+tEehY/Cm5FW1h+N6E09aJ0s2VhuclLyPcG/tSd7HZI0fPxUeoRvqZ6vv3InWSVfpxxEXmPcd537FrwTQMcblkRL36D04Z3hep1Qte9EPuvZUglfUtgilkk0CZnHdKh/llnXnaEAkdkN4xxMEIRDV7f2JfGgAnD/3CkM/5978nHmnBSZkrigt8VGL3GRng==" Apr 23 14:57:53 volumio go-librespot[4978]: time="2024-04-23T14:57: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-gew4.spotify.com:80]" Apr 23 14:57:54 volumio go-librespot[4978]: time="2024-04-23T14:57:54+09:00" level=debug msg="completed keyexchange" Apr 23 14:57:54 volumio go-librespot[4978]: time="2024-04-23T14:57:54+09:00" level=debug msg="completed challenge" Apr 23 14:57:54 volumio go-librespot[4978]: time="2024-04-23T14:57:54+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:57:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:57:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:57:54 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:57:55 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:57:55 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:55 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:57:55 volumio volumio[864]: (node:864) 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: 101) Apr 23 14:57:55 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 23 14:57:55 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:55 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:57:57 volumio volumio[864]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 23 14:57:57 volumio volumio[864]: info: touch_display: Setting screensaver timeout to 15 seconds. Apr 23 14:57:57 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 10 Apr 23 14:57:57 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 11 Apr 23 14:57:57 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:57:57 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:57:57 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:57:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:57:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Apr 23 14:57:57 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:57:57 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:57:57 volumio go-librespot[5017]: Librespot-go daemon starting... Apr 23 14:57:57 volumio go-librespot[5017]: time="2024-04-23T14:57:57+09:00" level=info msg="generated new device id: 2dfbc79a3a87cbf4ebc53c58f7f9737d68791221" Apr 23 14:57:57 volumio go-librespot[5017]: time="2024-04-23T14:57:57+09:00" level=debug msg="stored credentials not found" Apr 23 14:57:59 volumio go-librespot[5017]: time="2024-04-23T14:57:59+09:00" level=debug msg="obtained new client token: AABjoRmKjisFRj3K+UW4wk+E8eJZ21V0WZW6bzB8yFvWbv+1aA/t0sH1bamKNCUuXL44uxb4l9kGP6nkLnKYCRg+JxyQaFFzNDHUj2/J/oXIuqxpCrN4laTXyxko2A/zC8kvr5UnjIFMB+BAT9716mAEEPP3iwsStwfzrDGdHy4lgHFZz3yT8Ysaj5rHuKZr+NHmoEE3Bt6dw+naIWH2yAcwy7q36HZvech+BbZWTT74Irx/rYoqFPPCVGsgXQ==" Apr 23 14:57:59 volumio go-librespot[5017]: time="2024-04-23T14:57:59+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]" Apr 23 14:57:59 volumio go-librespot[5017]: time="2024-04-23T14:57:59+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:00 volumio go-librespot[5017]: time="2024-04-23T14:58:00+09:00" level=debug msg="completed challenge" Apr 23 14:58:00 volumio go-librespot[5017]: time="2024-04-23T14:58:00+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:00 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:00 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:03 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:03 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Apr 23 14:58:03 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:03 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:03 volumio go-librespot[5066]: Librespot-go daemon starting... Apr 23 14:58:03 volumio go-librespot[5066]: time="2024-04-23T14:58:03+09:00" level=info msg="generated new device id: 84ff3786d9a641a12a34e73a84d5d4a3245fecf7" Apr 23 14:58:03 volumio go-librespot[5066]: time="2024-04-23T14:58:03+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:04 volumio go-librespot[5066]: time="2024-04-23T14:58:04+09:00" level=debug msg="obtained new client token: AACkauEWwlWJDryuD+S5GfCqRldUNODldunxOPHvdjp43OA/dpH9HFGWzwDU3Al71C5KRVuX4/uj547ublzMur5qCNFOvs8feIjX6KJ/OM+tLAbV8uFOVePmVrOQ8okqfExcZE+FTfH+CiV0ziKlRKDHSOrXG+5KhaTK7Q8kx5ePLPSE7D1XXSRxoZreQH+PqP9mrimTPDL7KvNVAw7KRPxhEwszEwwsEMa9V43eWqSXmTOnLKL13iGF/9D0wQ==" Apr 23 14:58:05 volumio go-librespot[5066]: time="2024-04-23T14:58:05+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]" Apr 23 14:58:05 volumio go-librespot[5066]: time="2024-04-23T14:58:05+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:05 volumio go-librespot[5066]: time="2024-04-23T14:58:05+09:00" level=debug msg="completed challenge" Apr 23 14:58:05 volumio go-librespot[5066]: time="2024-04-23T14:58:05+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:06 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:06 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Apr 23 14:58:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:09 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:09 volumio go-librespot[5074]: Librespot-go daemon starting... Apr 23 14:58:09 volumio go-librespot[5074]: time="2024-04-23T14:58:09+09:00" level=info msg="generated new device id: 498eac4db6e5e874cab9f43b87577999dacb9e0d" Apr 23 14:58:09 volumio go-librespot[5074]: time="2024-04-23T14:58:09+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:09 volumio volumio[864]: verbose: New Socket.io Connection to 192.168.1.146 from 192.168.1.90 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_4_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 12 Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 23 14:58:09 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:09 volumio go-librespot[5074]: time="2024-04-23T14:58:09+09:00" level=debug msg="new websocket client" Apr 23 14:58:09 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::volumioGetVisibleSources Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 23 14:58:09 volumio volumio[864]: info: Received Get System Info Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 14:58:09 volumio volumio[864]: info: Discovery: Getting this device information Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:09 volumio volumio[864]: info: Listing playlists Apr 23 14:58:09 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 23 14:58:10 volumio go-librespot[5074]: time="2024-04-23T14:58:10+09:00" level=debug msg="obtained new client token: AABPYE88FlikASKImKt5n9bZrwh4m2ThCm6cOFOVenJeUTiACpNezSisicJ23e8wMhyrUuPGPhrmeul3wC5gtQV1K6R1VwAbGjKV4YXUUAEYSm9r5KEZzca3e+Ka7CMaVCbpPEZrbHM/Q0nLP6hEW4X7H2KkmLhNygipBZLI1RFr31nN/FixpdVRVhm0kijn4rl5ayC+gMDA/EMTAX6OZmnL+IT7wWLfV3itYehE4z0UvcU9lc7dlpOWYOS0tQ==" Apr 23 14:58:10 volumio volumio[864]: verbose: New Socket.io Connection to 192.168.1.146 from 192.168.1.90 UA: unknown Total Clients: 13 Apr 23 14:58:10 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:11 volumio go-librespot[5074]: time="2024-04-23T14:58: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]" Apr 23 14:58:11 volumio go-librespot[5074]: time="2024-04-23T14:58:11+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:11 volumio go-librespot[5074]: time="2024-04-23T14:58:11+09:00" level=debug msg="completed challenge" Apr 23 14:58:11 volumio go-librespot[5074]: time="2024-04-23T14:58:11+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:11 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:58:12 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:58:12 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:12 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:58:12 volumio volumio[864]: (node:864) 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: 102) Apr 23 14:58:12 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 14 Apr 23 14:58:12 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:12 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:58:14 volumio volumio[864]: info: CoreCommandRouter::volumioGetQueue Apr 23 14:58:14 volumio volumio[864]: info: CoreStateMachine::getQueue Apr 23 14:58:14 volumio volumio[864]: info: CorePlayQueue::getQueue Apr 23 14:58:14 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:14 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Apr 23 14:58:14 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:14 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:14 volumio go-librespot[5083]: Librespot-go daemon starting... Apr 23 14:58:15 volumio go-librespot[5083]: time="2024-04-23T14:58:15+09:00" level=info msg="generated new device id: a8bdc598803f8b147d45b021407c0a3d4bd21c63" Apr 23 14:58:15 volumio go-librespot[5083]: time="2024-04-23T14:58:15+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:15 volumio go-librespot[5083]: time="2024-04-23T14:58:15+09:00" level=debug msg="obtained new client token: AABfb2FF9+U9pL3otYFQj3tbaVcEinbPLCtHJOyH/p2ZMuRyVOVYsSrFR9/NkaUnEI9cxPfb9wZrgWlTNoF7FdfYcx1625RoRHfHhNgffgV9pWuQSInoLY9MCckHUKtR5aCy0rVBFemxFXkwmspdo5KjjizicKz5lZ4p8ppU69ozRRO8Xbfb0ioCH4sForOj9neapYT0itUD/Q8VqHruEgIwUv9flvP5t+YhKX2lUAOU6mTVcyu7xMR+N9Vx4w==" Apr 23 14:58:16 volumio go-librespot[5083]: time="2024-04-23T14:58:16+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]" Apr 23 14:58:16 volumio go-librespot[5083]: time="2024-04-23T14:58:16+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:17 volumio go-librespot[5083]: time="2024-04-23T14:58:17+09:00" level=debug msg="completed challenge" Apr 23 14:58:17 volumio go-librespot[5083]: time="2024-04-23T14:58:17+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:17 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:17 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Apr 23 14:58:20 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:20 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:20 volumio go-librespot[5095]: Librespot-go daemon starting... Apr 23 14:58:20 volumio go-librespot[5095]: time="2024-04-23T14:58:20+09:00" level=info msg="generated new device id: 05d8c3a3b720d08082f7ebfbcfbff9a5124ca21d" Apr 23 14:58:20 volumio go-librespot[5095]: time="2024-04-23T14:58:20+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:20 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:20 volumio go-librespot[5095]: time="2024-04-23T14:58:20+09:00" level=debug msg="new websocket client" Apr 23 14:58:20 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:58:21 volumio go-librespot[5095]: time="2024-04-23T14:58:21+09:00" level=debug msg="obtained new client token: AAAWCtH7uGqTtxGXmLTHOqOyiUt31X1XZkUw5Vs2xN5/4aLUeEdVvqxliHb45qYiZNfys6G+ZI78uGbTHySmTGZ53rXFT5OR9rvLXpcJsuBrArVs8PEYOf/u769au7D22V9JQ4k76GOm4ycn89syHOW4Jl4YFUoxLYE8OMHlkxW0FfzTj0UT1Aikc9vpotxMU1zhFxWnf9pg4zgpVFJPbivpwpdR8ekLlHxNRD3+n61+eLvVqx21/cqpKQI=" Apr 23 14:58:21 volumio go-librespot[5095]: time="2024-04-23T14:58:21+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]" Apr 23 14:58:21 volumio go-librespot[5095]: time="2024-04-23T14:58:21+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:22 volumio go-librespot[5095]: time="2024-04-23T14:58:22+09:00" level=debug msg="completed challenge" Apr 23 14:58:22 volumio go-librespot[5095]: time="2024-04-23T14:58:22+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:22 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:58:23 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:58:23 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:23 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:58:23 volumio volumio[864]: (node:864) 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: 103) Apr 23 14:58:23 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13 Apr 23 14:58:23 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:23 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:58:25 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:25 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Apr 23 14:58:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:25 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:25 volumio go-librespot[5104]: Librespot-go daemon starting... Apr 23 14:58:25 volumio go-librespot[5104]: time="2024-04-23T14:58:25+09:00" level=info msg="generated new device id: 7fc530311b3afd544d9fbdcd8a10ef1c347a98ce" Apr 23 14:58:25 volumio go-librespot[5104]: time="2024-04-23T14:58:25+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:26 volumio sudo[5112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 23 14:58:26 volumio sudo[5112]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:26 volumio sudo[5112]: pam_unix(sudo:session): session closed for user root Apr 23 14:58:26 volumio sudo[5115]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 23 14:58:26 volumio sudo[5115]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:26 volumio sudo[5115]: pam_unix(sudo:session): session closed for user root Apr 23 14:58:26 volumio volumio[864]: verbose: New Socket.io Connection to 192.168.1.146 from 192.168.1.90 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_4_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 12 Apr 23 14:58:26 volumio go-librespot[5104]: time="2024-04-23T14:58:26+09:00" level=debug msg="obtained new client token: AAB0nNN3A0zF7iWPf7cNegCyMzia6fZl5uIXRfGZSpqBoOnFKQ0q1NDFVOjB6jctqlnT3Zx4m1iKu8a2uvyjhEFVUEKAkzbgwTRVp6dCPvfgFaBL005YrBnuEUmTBjsrUU60G7O/+9XeayOasOYhCfqPxNGOP/vxOCamIDpZfgSE2jk6iHFXr/7qtjvi98QXDfTVsuxKm5jvudYl6IfkYSKZHgU+qrGcWdx05jm0JNgs9LufGNa6sta3nxiVdg==" Apr 23 14:58:26 volumio sudo[5119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 23 14:58:26 volumio sudo[5119]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:26 volumio sudo[5119]: pam_unix(sudo:session): session closed for user root Apr 23 14:58:26 volumio sudo[5122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 23 14:58:26 volumio sudo[5122]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:26 volumio sudo[5122]: pam_unix(sudo:session): session closed for user root Apr 23 14:58:26 volumio volumio[864]: verbose: New Socket.io Connection to 192.168.1.146 from 192.168.1.90 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_4_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 12 Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::volumioGetVisibleSources Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 23 14:58:26 volumio volumio[864]: info: Received Get System Info Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 14:58:26 volumio volumio[864]: info: Discovery: Getting this device information Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:26 volumio volumio[864]: info: Listing playlists Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 23 14:58:26 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 23 14:58:27 volumio go-librespot[5104]: time="2024-04-23T14:58: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 23 14:58:27 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 23 14:58:27 volumio go-librespot[5104]: time="2024-04-23T14:58:27+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:27 volumio go-librespot[5104]: time="2024-04-23T14:58:27+09:00" level=debug msg="completed challenge" Apr 23 14:58:27 volumio go-librespot[5104]: time="2024-04-23T14:58:27+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:28 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:28 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:28 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 23 14:58:28 volumio volumio[864]: info: Received Get System Info Apr 23 14:58:28 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 14:58:28 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 14:58:28 volumio volumio[864]: info: Discovery: Getting this device information Apr 23 14:58:28 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:28 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 14:58:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Apr 23 14:58:30 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:30 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:30 volumio go-librespot[5124]: Librespot-go daemon starting... Apr 23 14:58:31 volumio go-librespot[5124]: time="2024-04-23T14:58:31+09:00" level=info msg="generated new device id: 3b4bdea21165f4ade0330c3b5587cdb6d8747e6c" Apr 23 14:58:31 volumio go-librespot[5124]: time="2024-04-23T14:58:31+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:31 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:31 volumio go-librespot[5124]: time="2024-04-23T14:58:31+09:00" level=debug msg="new websocket client" Apr 23 14:58:31 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:58:31 volumio go-librespot[5124]: time="2024-04-23T14:58:31+09:00" level=debug msg="obtained new client token: AABf8U8DGXNgD5BtbgRyzZbEL1Ip83u4TkdomE0plsroAs+8uso6XoO4aXsdoQ7Qjq2ZkxpinS4aSByDwIIQpznd6X2+luCSr3pfXaRZoZw4fv4jPiC7qPEFCgOn+bTq47hVcO9GYnYSoGRKz4heqTYHCxSvKRpp7h5Y13RHR4QUNxK2ESHRvXcJGO8aIlO4ajXq6ncElGbX0wBwXOxo58CDhtleMsEC291mWImZb6jej4aSidH86VmqVbAHEQ==" Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 23 14:58:33 volumio volumio[864]: info: Retrieving Cloud Streaming UI Apr 23 14:58:33 volumio volumio[864]: info: Getting Tidal Cloud Configuration Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 23 14:58:33 volumio volumio[864]: info: Getting Qobuz Cloud Configuration Apr 23 14:58:33 volumio volumio[864]: info: Asking plugin for UI Config Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 23 14:58:33 volumio volumio[864]: info: Getting Spotify Cloud Configuration Apr 23 14:58:33 volumio volumio[864]: info: Asking plugin for UI Config Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 23 14:58:33 volumio volumio[864]: info: Saving Spotify Acccount Apr 23 14:58:33 volumio volumio[864]: info: Got Tidal Cloud Configuration Apr 23 14:58:33 volumio volumio[864]: info: Got it Apr 23 14:58:33 volumio volumio[864]: info: Got it Apr 23 14:58:33 volumio volumio[864]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 23 14:58:33 volumio volumio[864]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::volumioGetBrowseSources Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::volumioGetBrowseSources Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::volumioGetBrowseSources Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 23 14:58:33 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 23 14:58:33 volumio go-librespot[5124]: time="2024-04-23T14:58:33+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]" Apr 23 14:58:33 volumio go-librespot[5124]: time="2024-04-23T14:58:33+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:34 volumio go-librespot[5124]: time="2024-04-23T14:58:34+09:00" level=debug msg="completed challenge" Apr 23 14:58:34 volumio go-librespot[5124]: time="2024-04-23T14:58:34+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:34 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:58:34 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:58:34 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:34 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:58:34 volumio volumio[864]: (node:864) 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: 104) Apr 23 14:58:34 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13 Apr 23 14:58:34 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:34 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:58:37 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 23 14:58:37 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:37 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Apr 23 14:58:37 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:37 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:37 volumio go-librespot[5133]: Librespot-go daemon starting... Apr 23 14:58:37 volumio go-librespot[5133]: time="2024-04-23T14:58:37+09:00" level=info msg="generated new device id: 5c8ae575028b5b6e8556cd1f80897be23cf314d0" Apr 23 14:58:37 volumio go-librespot[5133]: time="2024-04-23T14:58:37+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:38 volumio go-librespot[5133]: time="2024-04-23T14:58:38+09:00" level=debug msg="obtained new client token: AAB6kQaM58LgA3U/rPdOrG0FYXHuUjd8X8ol2MZgfFil/tpvDCRMKMNbMBAlQXR4P7nvYekxbolxCTUb4Q4GSeUpcCsmXMG3XdhrkaFoXzPUUJB2IDBXEkUBLu19LRZzLgoPVrU7GDnFp3zQAa2aQTPUlBFm2/WsuMeE4in06MBwKgzzIT0tcmOf68kb77VjXCJSNy2oCmT/PbJLewJoUuNTtzNWTpFGclwbNY05f9dxyRDv6VX6ADjoo/E=" Apr 23 14:58:38 volumio go-librespot[5133]: time="2024-04-23T14:58:38+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]" Apr 23 14:58:39 volumio go-librespot[5133]: time="2024-04-23T14:58:39+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:39 volumio go-librespot[5133]: time="2024-04-23T14:58:39+09:00" level=debug msg="completed challenge" Apr 23 14:58:39 volumio go-librespot[5133]: time="2024-04-23T14:58:39+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:40 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:40 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:41 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 23 14:58:41 volumio volumio[864]: info: Disabling MyMusic plugin upnp Apr 23 14:58:41 volumio sudo[5142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 23 14:58:41 volumio sudo[5142]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:41 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Apr 23 14:58:41 volumio volumio[864]: error: Upnp client error: Error: This socket has been ended by the other party Apr 23 14:58:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Apr 23 14:58:42 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:43 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:43 volumio go-librespot[5144]: Librespot-go daemon starting... Apr 23 14:58:43 volumio go-librespot[5144]: time="2024-04-23T14:58:43+09:00" level=info msg="generated new device id: b0dd9635424ed7f854b676c45b3f7b66668e6888" Apr 23 14:58:43 volumio go-librespot[5144]: time="2024-04-23T14:58:43+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:43 volumio volumio[864]: info: Disabling MyMusic plugin airplay_emulation Apr 23 14:58:43 volumio volumio[864]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesShairport-Sync Apr 23 14:58:43 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 14:58:43 volumio volumio[864]: Cannot find translation for source 80s80s Radio Apr 23 14:58:43 volumio volumio[864]: Cannot find translation for source Podcast Apr 23 14:58:43 volumio volumio[864]: Cannot find translation for source Spotify Apr 23 14:58:43 volumio volumio[864]: info: Disabling plugin airplay_emulation Apr 23 14:58:43 volumio volumio[864]: info: Done. Apr 23 14:58:43 volumio sudo[5152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop shairport-sync Apr 23 14:58:43 volumio sudo[5152]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:43 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 23 14:58:43 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 23 14:58:43 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 23 14:58:43 volumio sudo[5152]: pam_unix(sudo:session): session closed for user root Apr 23 14:58:43 volumio volumio[864]: info: Shairport-Sync Stopped Apr 23 14:58:43 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:43 volumio go-librespot[5144]: time="2024-04-23T14:58:43+09:00" level=debug msg="new websocket client" Apr 23 14:58:43 volumio volumio[864]: info: Connection to go-librespot Websocket established Apr 23 14:58:43 volumio go-librespot[5144]: time="2024-04-23T14:58:43+09:00" level=debug msg="obtained new client token: AABTPI4oEdc4XSdb7Yh0qwccEDffr38hE6MaRHhay52dxscn22+BhEr2ktmXqsuzFrCziIH1HeFNG55XWXAIvYX/WoanJAsEO1M06et2jPXxjTG1q3NoxNEEaQsKeO+eJ0G20hewiaD5mk4CDbYmmgw6f/bzgOnHT9rT/yu2ICFHppWphnSuAkIkHvpvr0xMiT1Sgv1OgtmlCpa/R8yO8F+5tIDdunRvgO2+c4bJhxhKxQ3jwBsijfAGt7qqVw==" Apr 23 14:58:44 volumio go-librespot[5144]: time="2024-04-23T14:58:44+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]" Apr 23 14:58:44 volumio go-librespot[5144]: time="2024-04-23T14:58:44+09:00" level=debug msg="completed keyexchange" Apr 23 14:58:45 volumio go-librespot[5144]: time="2024-04-23T14:58:45+09:00" level=debug msg="completed challenge" Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 23 14:58:45 volumio go-librespot[5144]: time="2024-04-23T14:58:45+09:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: TravelRestriction" Apr 23 14:58:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 23 14:58:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 23 14:58:45 volumio volumio[864]: info: Connection to go-librespot Websocket closed Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 23 14:58:45 volumio volumio[864]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 23 14:58:45 volumio volumio[864]: info: Received Get System Version Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 14:58:45 volumio volumio[864]: info: Received Get System Info Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 14:58:45 volumio volumio[864]: info: Discovery: Getting this device information Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:45 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 14:58:46 volumio volumio[864]: info: Enabling MyMusic plugin airplay_emulation Apr 23 14:58:46 volumio volumio[864]: info: Enabling plugin airplay_emulation Apr 23 14:58:46 volumio volumio[864]: info: Loading plugin "airplay_emulation"... Apr 23 14:58:46 volumio volumio[864]: info: Starting Shairport Sync Apr 23 14:58:46 volumio volumio[864]: info: PLUGIN START: airplay_emulation Apr 23 14:58:46 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:58:46 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 14:58:46 volumio volumio[864]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 14:58:46 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 14:58:46 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 14:58:46 volumio volumio[864]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 14:58:46 volumio volumio[864]: info: Done. Apr 23 14:58:46 volumio volumio[864]: info: Starting Shairport Sync Apr 23 14:58:46 volumio volumio[864]: info: Starting Shairport Sync Apr 23 14:58:46 volumio sudo[5162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 14:58:46 volumio sudo[5162]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:46 volumio sudo[5165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 14:58:46 volumio sudo[5165]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:46 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 23 14:58:46 volumio sudo[5162]: pam_unix(sudo:session): session closed for user root Apr 23 14:58:46 volumio volumio[864]: info: Shairport-Sync Started Apr 23 14:58:46 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 23 14:58:46 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 23 14:58:46 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 23 14:58:46 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 23 14:58:46 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 23 14:58:46 volumio sudo[5165]: pam_unix(sudo:session): session closed for user root Apr 23 14:58:46 volumio volumio[864]: info: Shairport-Sync Started Apr 23 14:58:46 volumio volumio[864]: info: Getting Spotify volume Apr 23 14:58:46 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:46 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 23 14:58:46 volumio volumio[864]: (node:864) 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: 105) Apr 23 14:58:46 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 13 Apr 23 14:58:46 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Apr 23 14:58:46 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Apr 23 14:58:47 volumio volumio[864]: info: Disabling MyMusic plugin upnp Apr 23 14:58:47 volumio sudo[5174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 23 14:58:47 volumio sudo[5174]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 14:58:48 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Apr 23 14:58:48 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 23 14:58:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 23 14:58:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Apr 23 14:58:48 volumio systemd[1]: Stopped go-librespot Daemon. Apr 23 14:58:48 volumio systemd[1]: Started go-librespot Daemon. Apr 23 14:58:48 volumio go-librespot[5176]: Librespot-go daemon starting... Apr 23 14:58:48 volumio go-librespot[5176]: time="2024-04-23T14:58:48+09:00" level=info msg="generated new device id: cb9385b12f60ba908b1f86597732b98c2528f5db" Apr 23 14:58:48 volumio go-librespot[5176]: time="2024-04-23T14:58:48+09:00" level=debug msg="stored credentials not found" Apr 23 14:58:48 volumio volumio[864]: info: Enabling MyMusic plugin upnp Apr 23 14:58:48 volumio volumio[864]: info: Enabling plugin upnp Apr 23 14:58:48 volumio volumio[864]: info: Loading plugin "upnp"... Apr 23 14:58:48 volumio volumio[864]: info: [1713851928880] Starting Upmpd Daemon Apr 23 14:58:48 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 23 14:58:48 volumio volumio[864]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 14:58:48 volumio volumio[864]: Error: listen EADDRINUSE: address already in use :::6599 Apr 23 14:58:48 volumio volumio[864]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Apr 23 14:58:48 volumio volumio[864]: at listenInCluster (net.js:1366:12) Apr 23 14:58:48 volumio volumio[864]: at Server.listen (net.js:1452:7) Apr 23 14:58:48 volumio volumio[864]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Apr 23 14:58:48 volumio volumio[864]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Apr 23 14:58:48 volumio volumio[864]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 23 14:58:48 volumio volumio[864]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 23 14:58:48 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Apr 23 14:58:48 volumio volumio[864]: code: 'EADDRINUSE', Apr 23 14:58:48 volumio volumio[864]: errno: -98, Apr 23 14:58:48 volumio volumio[864]: syscall: 'listen', Apr 23 14:58:48 volumio volumio[864]: address: '::', Apr 23 14:58:48 volumio volumio[864]: port: 6599 Apr 23 14:58:48 volumio volumio[864]: } Apr 23 14:58:48 volumio volumio[864]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 14:58:49 volumio go-librespot[5176]: time="2024-04-23T14:58:49+09:00" level=debug msg="obtained new client token: AAAZJTQ0pkwvzzQyjAwjZVF82EO6BkqvA/bsllgLk10G5OZ14oJnASN1Ihvc4vlNtt3B2IEg/e3q3ba7KdXOxyfSGQ4QmOztLIE4YUjp+Ps8sW9XajSrZ5PF5vEJAOshYgm3Iz2T8nHCLX6/+2HUIQ9shBgJLVmaS9i5RwPn/MJ/vSxCgK+qR3weXHqFW05JjU9/BfDRtRbF/hUIMtDtUw+BzDuZd0aX3uhGZDx0bR4pN7EOeD5ru8+YXMQ=" Apr 23 14:58:49 volumio sudo[5193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-23 14:57 Apr 23 14:58:49 volumio sudo[5193]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"