-- Logs begin at Thu 2024-10-24 13:42:02 WAT, end at Sat 2024-10-26 11:57:05 WAT. -- Oct 26 11:56:00 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:00 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 26 11:56:01 volumio volumio[4861]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 26 11:56:01 volumio volumio[4861]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 26 11:56:03 volumio go-librespot[5157]: time="2024-10-26T11:56:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp 35.186.224.24:443: i/o timeout" Oct 26 11:56:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 26 11:56:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 26 11:56:03 volumio volumio[4861]: (node:4861) UnhandledPromiseRejectionWarning: Error: socket hang up Oct 26 11:56:03 volumio volumio[4861]: at connResetException (internal/errors.js:607:14) Oct 26 11:56:03 volumio volumio[4861]: at Socket.socketOnEnd (_http_client.js:493:23) Oct 26 11:56:03 volumio volumio[4861]: at Socket.emit (events.js:327:22) Oct 26 11:56:03 volumio volumio[4861]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 26 11:56:03 volumio volumio[4861]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 26 11:56:03 volumio volumio[4861]: (node:4861) 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: 2) Oct 26 11:56:03 volumio volumio[4861]: info: Connection to go-librespot Websocket closed Oct 26 11:56:04 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:06 volumio volumio[4861]: info: Initializing connection to go-librespot Websocket Oct 26 11:56:06 volumio volumio[4861]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 26 11:56:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 26 11:56:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Oct 26 11:56:06 volumio systemd[1]: Stopped go-librespot Daemon. Oct 26 11:56:06 volumio systemd[1]: Started go-librespot Daemon. Oct 26 11:56:06 volumio go-librespot[5236]: Librespot-go daemon starting... Oct 26 11:56:06 volumio go-librespot[5236]: time="2024-10-26T11:56:06+01:00" level=info msg="generated new device id: 2088edd13f4f7f93bb9ceb3d6c9a91935f922210" Oct 26 11:56:06 volumio go-librespot[5236]: time="2024-10-26T11:56:06+01:00" level=debug msg="stored credentials found for collinskcs" Oct 26 11:56:07 volumio volumio[4861]: info: CoreCommandRouter::volumioGetState Oct 26 11:56:07 volumio volumio[4861]: info: CorePlayQueue::getTrack 0 Oct 26 11:56:07 volumio volumio[4861]: info: CoreCommandRouter::volumioGetQueue Oct 26 11:56:07 volumio volumio[4861]: info: CoreStateMachine::getQueue Oct 26 11:56:07 volumio volumio[4861]: info: CorePlayQueue::getQueue Oct 26 11:56:08 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:09 volumio go-librespot[5236]: time="2024-10-26T11:56:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 26 11:56:09 volumio go-librespot[5236]: time="2024-10-26T11:56:09+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 26 11:56:09 volumio go-librespot[5236]: time="2024-10-26T11:56:09+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 26 11:56:09 volumio go-librespot[5236]: time="2024-10-26T11:56:09+01:00" level=debug msg="zeroconf server listening on port 40269" Oct 26 11:56:09 volumio volumio[4861]: info: Initializing connection to go-librespot Websocket Oct 26 11:56:09 volumio go-librespot[5236]: time="2024-10-26T11:56:09+01:00" level=debug msg="new websocket client" Oct 26 11:56:09 volumio volumio[4861]: info: Connection to go-librespot Websocket established Oct 26 11:56:12 volumio go-librespot[5236]: time="2024-10-26T11:56:12+01:00" level=debug msg="obtained new client token: AACLZisVF4IYcfY2LIRJt26v/Au2aoFfQvHFD3o5gjok5a/VUkUC5tWrelug06QM0+3b5HZVonFYn74JdOAyJMPmyQYnD/jigKUgtIL3rKlT08rhAcHFBMuSP28O9a4w9bZRiCoMvI/Hs+3lRRnznQOdK7z7ZfxtiwBiJj7pA1ERRPfoDlG2jWM/e8AMDjN5FXqvxrbIMD3z4QjefNd1O9X5odO3uWS3tqCAs+n9/q7KalnTYqTx1p1t" Oct 26 11:56:12 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:12 volumio volumio[4861]: info: Getting Spotify volume Oct 26 11:56:12 volumio volumio[4861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 26 11:56:12 volumio volumio[4861]: Error Reading Tinyart path: Error: ENOENT: no such file or directory, open '/data/albumart/web/Kelly%20Rowland/119ae5a0-521e-4824-80dc-518a599f9a05.jpg' Oct 26 11:56:12 volumio volumio[4861]: info: CoreCommandRouter::volumioGetState Oct 26 11:56:12 volumio volumio[4861]: info: CorePlayQueue::getTrack 0 Oct 26 11:56:12 volumio volumio[4861]: SPOTIFY: RECEIVED VOLUMIO VOLUME 4 Oct 26 11:56:15 volumio volumio[4861]: error: error Oct 26 11:56:15 volumio volumio[4861]: error: error Oct 26 11:56:15 volumio volumio[4861]: info: CoreCommandRouter::volumioGetQueue Oct 26 11:56:15 volumio volumio[4861]: info: CoreStateMachine::getQueue Oct 26 11:56:15 volumio volumio[4861]: info: CorePlayQueue::getQueue Oct 26 11:56:16 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:20 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:22 volumio hostapd[881]: wlan0: STA 78:3a:6c:86:0a:6f IEEE 802.11: disassociated Oct 26 11:56:22 volumio hostapd[881]: wlan0: STA 78:3a:6c:86:0a:6f IEEE 802.11: disassociated Oct 26 11:56:24 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:28 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:33 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:36 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:40 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:44 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:48 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:52 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:56 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:56:59 volumio volumio[4861]: info: An error occurred while refreshing Spotify Token Error: connect ETIMEDOUT 66.241.124.64:443 Oct 26 11:57:00 volumio volumio[4861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 11:57:04 volumio sudo[5286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 26 11:57:04 volumio sudo[5286]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 11:57:04 volumio sudo[5286]: pam_unix(sudo:session): session closed for user root Oct 26 11:57:04 volumio sudo[5289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 26 11:57:04 volumio sudo[5289]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 11:57:04 volumio sudo[5289]: pam_unix(sudo:session): session closed for user root Oct 26 11:57:04 volumio volumio[4861]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.254 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Safari/537.36 Edg/130.0.0.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 26 11:57:04 volumio volumio[4861]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.757&uuid=02799dfb2647bb3ffb25c24607128774" http://updates.volumio.org/downloader-v1/track-device Oct 26 11:57:04 volumio volumio[4861]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 26 11:57:04 volumio volumio[4861]: Dload Upload Total Spent Left Speed Oct 26 11:57:04 volumio volumio[4861]: [10.7K blob data] Oct 26 11:57:04 volumio volumio[4861]: curl: (28) Failed to connect to updates.volumio.org port 80: Connection timed out Oct 26 11:57:04 volumio volumio[4861]: retrying in 5 seconds, trial 0 Oct 26 11:57:04 volumio volumio[4861]: info: Volumio Calling Home Oct 26 11:57:04 volumio sudo[5294]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 26 11:57:04 volumio sudo[5294]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 11:57:04 volumio sudo[5294]: pam_unix(sudo:session): session closed for user root Oct 26 11:57:04 volumio sudo[5297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 26 11:57:04 volumio sudo[5297]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 11:57:04 volumio sudo[5297]: pam_unix(sudo:session): session closed for user root Oct 26 11:57:04 volumio volumio[4861]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.254 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Safari/537.36 Edg/130.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 26 11:57:04 volumio volumio[4861]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 11:57:04 volumio volumio[4861]: Error: connect ETIMEDOUT 151.101.66.79:80 Oct 26 11:57:04 volumio volumio[4861]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Oct 26 11:57:04 volumio volumio[4861]: errno: -110, Oct 26 11:57:04 volumio volumio[4861]: code: 'ETIMEDOUT', Oct 26 11:57:04 volumio volumio[4861]: syscall: 'connect', Oct 26 11:57:04 volumio volumio[4861]: address: '151.101.66.79', Oct 26 11:57:04 volumio volumio[4861]: port: 80 Oct 26 11:57:04 volumio volumio[4861]: } Oct 26 11:57:04 volumio volumio[4861]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 11:57:05 volumio sudo[5309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-26 11:56 Oct 26 11:57:05 volumio sudo[5309]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"