-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2024-10-13 00:02:10 CEST. -- Oct 13 00:01:04 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 00:01:04 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 00:01:04 volumio volumio[916]: info: Discovery: Getting this device information Oct 13 00:01:04 volumio volumio[916]: info: CoreCommandRouter::volumioGetState Oct 13 00:01:04 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 00:01:09 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 00:01:09 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 00:01:20 volumio volumio[916]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf Oct 13 00:01:22 volumio volumio[916]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf Oct 13 00:01:22 volumio volumio[916]: info: Folder /tmp/plugins removed Oct 13 00:01:22 volumio volumio[916]: info: Check plugin dependencies Oct 13 00:01:22 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 00:01:22 volumio volumio[916]: info: Checking if plugin already exists Oct 13 00:01:22 volumio volumio[916]: info: Rename folder Oct 13 00:01:22 volumio volumio[916]: info: Folder /tmp/downloaded_plugin.zip removed Oct 13 00:01:22 volumio volumio[916]: info: Move to category Oct 13 00:01:23 volumio volumio[916]: info: Checking if install.sh is present Oct 13 00:01:23 volumio volumio[916]: info: Executing install.sh Oct 13 00:01:23 volumio sudo[2085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh Oct 13 00:01:23 volumio sudo[2085]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 00:01:23 volumio volumio[916]: info: Installing Go-librespot Oct 13 00:01:23 volumio volumio[916]: info: Checking old vollibrespot installs Oct 13 00:01:23 volumio systemd[1]: Reloading. Oct 13 00:01:24 volumio 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 13 00:01:24 volumio volumio[916]: info: Dowloading daemon Oct 13 00:01:25 volumio volumio[916]: info: Creating Start Script Oct 13 00:01:25 volumio systemd[1]: Reloading. Oct 13 00:01:25 volumio 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 13 00:01:26 volumio sudo[2085]: pam_unix(sudo:session): session closed for user root Oct 13 00:01:26 volumio volumio[916]: Plugin install end detected on script Oct 13 00:01:26 volumio volumio[916]: info: Install script completed Oct 13 00:01:26 volumio volumio[916]: info: Adding reference to registry Oct 13 00:01:26 volumio volumio[916]: info: Done installing plugin. Oct 13 00:01:26 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 00:01:26 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 00:01:26 volumio volumio[916]: info: Folder /tmp/plugins removed Oct 13 00:01:26 volumio volumio[916]: info: Folder /tmp/downloaded_plugin.zip removed Oct 13 00:01:26 volumio volumio[916]: info: Folder /data/temp removed Oct 13 00:01:27 volumio volumio[916]: info: Enabling plugin spop Oct 13 00:01:27 volumio volumio[916]: info: Loading plugin "spop"... Oct 13 00:01:28 volumio volumio[916]: info: PLUGIN START: spop Oct 13 00:01:28 volumio volumio[916]: info: Creating Spotify config file Oct 13 00:01:28 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 00:01:28 volumio volumio[916]: info: Done. Oct 13 00:01:28 volumio volumio[916]: info: Spotify config file written Oct 13 00:01:28 volumio volumio[916]: info: No need to fix Spotify hosts Oct 13 00:01:28 volumio sudo[2130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 13 00:01:28 volumio sudo[2130]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 00:01:28 volumio systemd[1]: Started go-librespot Daemon. Oct 13 00:01:28 volumio go-librespot[2132]: Librespot-go daemon starting... Oct 13 00:01:28 volumio sudo[2130]: pam_unix(sudo:session): session closed for user root Oct 13 00:01:28 volumio go-librespot[2132]: time="2024-10-13T00:01:28+02:00" level=info msg="generated new device id: 992c0abfd379c20e042ec0e937b4b457b9cc2ec6" Oct 13 00:01:28 volumio go-librespot[2132]: time="2024-10-13T00:01:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 13 00:01:28 volumio go-librespot[2132]: time="2024-10-13T00:01:28+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 13 00:01:28 volumio go-librespot[2132]: time="2024-10-13T00:01:28+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 13 00:01:28 volumio go-librespot[2132]: time="2024-10-13T00:01:28+02:00" level=debug msg="zeroconf server listening on port 34803" Oct 13 00:01:31 volumio volumio[916]: info: go-librespot daemon successfully initialized Oct 13 00:01:34 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 00:01:34 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 00:01:34 volumio volumio[916]: info: Discovery: Getting this device information Oct 13 00:01:34 volumio volumio[916]: info: CoreCommandRouter::volumioGetState Oct 13 00:01:34 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 00:01:34 volumio volumio[916]: info: Initializing connection to go-librespot Websocket Oct 13 00:01:34 volumio go-librespot[2132]: time="2024-10-13T00:01:34+02:00" level=debug msg="new websocket client" Oct 13 00:01:34 volumio volumio[916]: info: Connection to go-librespot Websocket established Oct 13 00:01:36 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:01:36 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 13 00:01:36 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 13 00:01:36 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 13 00:01:36 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 13 00:01:36 volumio volumio[916]: info: Received Get System Version Oct 13 00:01:36 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 00:01:37 volumio volumio[916]: info: Getting Spotify volume Oct 13 00:01:37 volumio volumio[916]: 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 13 00:01:37 volumio volumio[916]: info: CoreCommandRouter::volumioGetState Oct 13 00:01:37 volumio volumio[916]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 00:01:37 volumio volumio[916]: SPOTIFY: SPOTIFY VOLUME undefined Oct 13 00:01:37 volumio volumio[916]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 00:01:37 volumio volumio[916]: info: Aligning Spotify Volume to Volumio Volume Oct 13 00:01:37 volumio volumio[916]: info: CoreCommandRouter::volumioGetState Oct 13 00:01:37 volumio volumio[916]: info: Setting Spotify Volume from Volumio: 100 Oct 13 00:01:39 volumio volumio[916]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Oct 13 00:01:39 volumio volumio[916]: info: Sending Spotify command with payload to local API: /player/volume Oct 13 00:01:49 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:01:49 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 13 00:01:49 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 13 00:01:49 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 13 00:01:49 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 13 00:01:49 volumio volumio[916]: info: Received Get System Version Oct 13 00:01:49 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 00:02:04 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 00:02:04 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 00:02:04 volumio volumio[916]: info: Discovery: Getting this device information Oct 13 00:02:04 volumio volumio[916]: info: CoreCommandRouter::volumioGetState Oct 13 00:02:04 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 00:02:05 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:02:05 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:02:05 volumio volumio[916]: info: Retrieving Cloud Streaming UI Oct 13 00:02:05 volumio volumio[916]: info: Getting Tidal Cloud Configuration Oct 13 00:02:05 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:02:05 volumio volumio[916]: info: Getting Qobuz Cloud Configuration Oct 13 00:02:05 volumio volumio[916]: info: Asking plugin for UI Config Oct 13 00:02:05 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:02:05 volumio volumio[916]: info: Getting Spotify Cloud Configuration Oct 13 00:02:05 volumio volumio[916]: info: Asking plugin for UI Config Oct 13 00:02:05 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:02:05 volumio volumio[916]: info: Saving Spotify Acccount Oct 13 00:02:05 volumio volumio[916]: info: Got Tidal Cloud Configuration Oct 13 00:02:05 volumio volumio[916]: info: Got it Oct 13 00:02:05 volumio volumio[916]: info: Got it Oct 13 00:02:05 volumio volumio[916]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 13 00:02:05 volumio volumio[916]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 00:02:05 volumio volumio[916]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::volumioGetBrowseSources Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::volumioGetBrowseSources Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::volumioGetBrowseSources Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 13 00:02:06 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 13 00:02:08 volumio volumio[916]: info: Disabling MyMusic plugin upnp Oct 13 00:02:08 volumio sudo[2212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Oct 13 00:02:08 volumio sudo[2212]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 13 00:02:08 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Oct 13 00:02:08 volumio volumio[916]: error: Upnp client error: Error: This socket has been ended by the other party Oct 13 00:02:10 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 13 00:02:10 volumio volumio[916]: info: Enabling MyMusic plugin upnp Oct 13 00:02:10 volumio volumio[916]: info: Enabling plugin upnp Oct 13 00:02:10 volumio volumio[916]: info: Loading plugin "upnp"... Oct 13 00:02:10 volumio volumio[916]: info: [1728770530094] Starting Upmpd Daemon Oct 13 00:02:10 volumio volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 13 00:02:10 volumio volumio[916]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 00:02:10 volumio volumio[916]: Error: listen EADDRINUSE: address already in use :::6599 Oct 13 00:02:10 volumio volumio[916]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Oct 13 00:02:10 volumio volumio[916]: at listenInCluster (net.js:1366:12) Oct 13 00:02:10 volumio volumio[916]: at Server.listen (net.js:1452:7) Oct 13 00:02:10 volumio volumio[916]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Oct 13 00:02:10 volumio volumio[916]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Oct 13 00:02:10 volumio volumio[916]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Oct 13 00:02:10 volumio volumio[916]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 13 00:02:10 volumio volumio[916]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Oct 13 00:02:10 volumio volumio[916]: code: 'EADDRINUSE', Oct 13 00:02:10 volumio volumio[916]: errno: -98, Oct 13 00:02:10 volumio volumio[916]: syscall: 'listen', Oct 13 00:02:10 volumio volumio[916]: address: '::', Oct 13 00:02:10 volumio volumio[916]: port: 6599 Oct 13 00:02:10 volumio volumio[916]: } Oct 13 00:02:10 volumio volumio[916]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 00:02:10 volumio sudo[2223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-13 00:01 Oct 13 00:02:10 volumio sudo[2223]: 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"