-- Logs begin at Tue 2024-09-17 11:06:55 EDT, end at Fri 2024-10-11 15:12:49 EDT. -- Oct 11 15:11:11 localhost volumio[692]: info: Creating Start Script Oct 11 15:11:11 localhost systemd[1]: Reloading. Oct 11 15:11:15 localhost volumio[692]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf Oct 11 15:11:15 localhost volumio[692]: info: Folder /tmp/plugins removed Oct 11 15:11:21 localhost systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Oct 11 15:11:28 localhost sudo[9776]: pam_unix(sudo:session): session closed for user root Oct 11 15:11:28 localhost volumio[692]: Plugin install end detected on script Oct 11 15:11:28 localhost volumio[692]: info: Install script completed Oct 11 15:11:28 localhost volumio[692]: info: Adding reference to registry Oct 11 15:11:29 localhost volumio[692]: info: Done installing plugin. Oct 11 15:11:29 localhost volumio[692]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 15:11:29 localhost volumio[692]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 11 15:11:29 localhost volumio[692]: info: Folder /tmp/plugins removed Oct 11 15:11:30 localhost volumio[692]: info: Folder /tmp/downloaded_plugin.zip removed Oct 11 15:11:40 localhost volumio[692]: info: Enabling plugin spop Oct 11 15:11:40 localhost volumio[692]: info: Enabling plugin spop Oct 11 15:11:40 localhost volumio[692]: info: Loading plugin "spop"... Oct 11 15:11:53 localhost volumio-remote-updater[476]: [2024-10-11 15:11:53] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Oct 11 15:11:58 localhost volumio-remote-updater[476]: [2024-10-11 15:11:58] [connect] Successful connection Oct 11 15:12:01 localhost volumio[692]: info: Loading plugin "spop"... Oct 11 15:12:01 localhost volumio[692]: info: PLUGIN START: spop Oct 11 15:12:01 localhost volumio[692]: info: Creating Spotify config file Oct 11 15:12:01 localhost volumio[692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:12:01 localhost volumio[692]: info: PLUGIN START: spop Oct 11 15:12:01 localhost volumio[692]: info: Creating Spotify config file Oct 11 15:12:01 localhost volumio[692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:12:01 localhost volumio[692]: info: Done. Oct 11 15:12:01 localhost volumio[692]: info: Done. Oct 11 15:12:02 localhost volumio[692]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Oct 11 15:12:11 localhost volumio-remote-updater[476]: [2024-10-11 15:12:11] [connect] Successful connection Oct 11 15:12:11 localhost volumio[692]: info: Check plugin dependencies Oct 11 15:12:12 localhost volumio[692]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 11 15:12:12 localhost volumio[692]: info: Checking if plugin already exists Oct 11 15:12:12 localhost volumio[692]: info: An error occurred installing the plugin. Rolling back config Oct 11 15:12:12 localhost volumio[692]: info: Plugin folders cleanup Oct 11 15:12:12 localhost volumio[692]: info: Scanning into folder /volumio/app/plugins/ Oct 11 15:12:12 localhost volumio[692]: info: Scanning category audio_interface Oct 11 15:12:12 localhost volumio[692]: info: Scanning category miscellanea Oct 11 15:12:12 localhost volumio[692]: info: Scanning category music_service Oct 11 15:12:12 localhost volumio[692]: info: Scanning category plugins.json Oct 11 15:12:12 localhost volumio[692]: info: Scanning category system_controller Oct 11 15:12:12 localhost volumio[692]: info: Scanning category user_interface Oct 11 15:12:12 localhost volumio[692]: info: Scanning into folder /data/plugins/ Oct 11 15:12:12 localhost volumio[692]: info: Scanning category music_service Oct 11 15:12:12 localhost volumio[692]: info: Scanning category user_interface Oct 11 15:12:12 localhost volumio[692]: info: Plugin folders cleanup completed Oct 11 15:12:12 localhost volumio[692]: info: Error: Error Oct 11 15:12:13 localhost volumio[692]: info: Folder /tmp/downloaded_plugin.zip removed Oct 11 15:12:13 localhost volumio[692]: info: Folder /tmp/plugins removed Oct 11 15:12:13 localhost volumio[692]: info: Folder /tmp/downloaded_plugin.zip removed Oct 11 15:12:13 localhost volumio[692]: verbose: New Socket.io Connection to 192.168.12.13 from 192.168.12.236 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 11 15:12:13 localhost volumio[692]: verbose: New Socket.io Connection to 192.168.12.13 from 192.168.12.236 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Oct 11 15:12:14 localhost volumio[692]: info: Spotify config file written Oct 11 15:12:15 localhost volumio[692]: info: Spotify config file written Oct 11 15:12:16 localhost volumio[692]: verbose: New Socket.io Connection to 192.168.12.13 from 192.168.12.236 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Oct 11 15:12:16 localhost volumio-remote-updater[476]: [2024-10-11 15:12:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1728673931 101 Oct 11 15:12:16 localhost volumio[692]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Oct 11 15:12:16 localhost sudo[9907]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 11 15:12:16 localhost sudo[9909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 11 15:12:16 localhost volumio[692]: verbose: New Socket.io Connection to 192.168.12.13 from 192.168.12.236 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Oct 11 15:12:16 localhost sudo[9907]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:12:16 localhost sudo[9909]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:12:17 localhost volumio[692]: info: No need to fix Spotify hosts Oct 11 15:12:17 localhost volumio[692]: info: No need to fix Spotify hosts Oct 11 15:12:17 localhost volumio[692]: 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 11 15:12:17 localhost systemd[1]: Started go-librespot Daemon. Oct 11 15:12:18 localhost go-librespot[9913]: Librespot-go daemon starting... Oct 11 15:12:18 localhost sudo[9907]: pam_unix(sudo:session): session closed for user root Oct 11 15:12:18 localhost sudo[9909]: pam_unix(sudo:session): session closed for user root Oct 11 15:12:18 localhost volumio[692]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 11 15:12:18 localhost go-librespot[9913]: time="2024-10-11T15:12:18-04:00" level=info msg="generated new device id: ab089c418db6976ad7602ee73d23ae3a04fdd9bb" Oct 11 15:12:19 localhost volumio[692]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 11 15:12:19 localhost volumio[692]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 11 15:12:19 localhost volumio[692]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Oct 11 15:12:20 localhost volumio[692]: verbose: New Socket.io Connection to 192.168.12.13 from 192.168.12.236 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Oct 11 15:12:20 localhost volumio[692]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv6l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Oct 11 15:12:23 localhost volumio[692]: info: CoreCommandRouter::volumioGetState Oct 11 15:12:23 localhost volumio[692]: info: CorePlayQueue::getTrack 0 Oct 11 15:12:24 localhost volumio[692]: verbose: New Socket.io Connection to 192.168.12.13 from 192.168.12.236 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Oct 11 15:12:24 localhost go-librespot[9913]: time="2024-10-11T15:12:24-04:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 11 15:12:24 localhost go-librespot[9913]: time="2024-10-11T15:12:24-04:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 11 15:12:24 localhost go-librespot[9913]: time="2024-10-11T15:12:24-04:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 11 15:12:24 localhost go-librespot[9913]: time="2024-10-11T15:12:24-04:00" level=debug msg="zeroconf server listening on port 32941" Oct 11 15:12:25 localhost volumio[692]: info: go-librespot daemon successfully initialized Oct 11 15:12:25 localhost volumio[692]: info: go-librespot daemon successfully initialized Oct 11 15:12:29 localhost volumio[692]: info: Initializing connection to go-librespot Websocket Oct 11 15:12:29 localhost volumio[692]: info: Initializing connection to go-librespot Websocket Oct 11 15:12:30 localhost go-librespot[9913]: time="2024-10-11T15:12:30-04:00" level=debug msg="new websocket client" Oct 11 15:12:30 localhost go-librespot[9913]: time="2024-10-11T15:12:30-04:00" level=debug msg="new websocket client" Oct 11 15:12:30 localhost volumio[692]: info: Connection to go-librespot Websocket established Oct 11 15:12:30 localhost volumio[692]: verbose: New Socket.io Connection to 192.168.12.13 from 192.168.12.236 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Oct 11 15:12:31 localhost volumio[692]: info: Connection to go-librespot Websocket established Oct 11 15:12:32 localhost volumio[692]: info: Folder /data/temp removed Oct 11 15:12:32 localhost volumio[692]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 15:12:32 localhost volumio[692]: Error: Unable to resolve or reject the same promise twice Oct 11 15:12:32 localhost volumio[692]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Oct 11 15:12:32 localhost volumio[692]: at /volumio/app/pluginmanager.js:1087:11 Oct 11 15:12:32 localhost volumio[692]: at CB (/volumio/node_modules/fs-extra/lib/remove/rimraf.js:57:5) Oct 11 15:12:32 localhost volumio[692]: at /volumio/node_modules/fs-extra/lib/remove/rimraf.js:213:24 Oct 11 15:12:32 localhost volumio[692]: at CB (/volumio/node_modules/fs-extra/lib/remove/rimraf.js:57:5) Oct 11 15:12:32 localhost volumio[692]: at /volumio/node_modules/fs-extra/lib/remove/rimraf.js:213:24 Oct 11 15:12:32 localhost volumio[692]: at CB (/volumio/node_modules/fs-extra/lib/remove/rimraf.js:57:5) Oct 11 15:12:32 localhost volumio[692]: at FSReqCallback.oncomplete (fs.js:171:23) Oct 11 15:12:32 localhost volumio[692]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 15:12:46 localhost volumio-remote-updater[476]: [2024-10-11 15:12:46] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Oct 11 15:12:49 localhost sudo[9997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-11 15:11 Oct 11 15:12:49 localhost sudo[9997]: 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"