-- Logs begin at Wed 2024-08-21 07:29:11 CEST, end at Tue 2024-08-27 00:32:13 CEST. -- Aug 27 00:31:03 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-DISCONNECTED bssid=fa:92:bf:62:ad:85 reason=3 Aug 27 00:31:03 lms-sdb dhcpcd[1141]: wlan0: carrier lost Aug 27 00:31:03 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Aug 27 00:31:03 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=FR Aug 27 00:31:03 lms-sdb avahi-daemon[648]: Withdrawing address record for 192.168.30.15 on wlan0. Aug 27 00:31:03 lms-sdb avahi-daemon[648]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.30.15. Aug 27 00:31:03 lms-sdb avahi-daemon[648]: Interface wlan0.IPv4 no longer relevant for mDNS. Aug 27 00:31:03 lms-sdb dhcpcd[1141]: wlan0: deleting route to 192.168.30.0/24 Aug 27 00:31:03 lms-sdb dhcpcd[1141]: wlan0: deleting default route via 192.168.30.1 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: A device disappeared from network Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Device lms-chambre disappeared from network Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.11 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: A device disappeared from network Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Device lms-cave disappeared from network Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.14 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Disconnected from remote: 192.168.30.14 Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: A device disappeared from network Aug 27 00:31:03 lms-sdb volumio[29767]: info: Discovery: Device lms-sdb disappeared from network Aug 27 00:31:05 lms-sdb ntpd[778]: Deleting interface #4 wlan0, 192.168.30.15#123, interface stats: received=23273, sent=24378, dropped=0, active_time=1663516 secs Aug 27 00:31:05 lms-sdb ntpd[778]: 78.197.169.39 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 188.165.42.144 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 51.254.208.135 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 141.95.158.40 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 82.64.203.110 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 188.213.26.33 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 162.159.200.123 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 5.196.160.139 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 51.75.17.219 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 213.251.128.249 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 217.182.137.208 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 51.210.104.72 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 5.196.95.236 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 37.187.102.143 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 37.187.150.174 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 82.64.42.185 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 82.64.84.116 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 51.255.141.76 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 54.36.61.42 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 89.168.36.197 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 176.142.73.191 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 178.32.23.17 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 176.137.36.37 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 45.13.105.44 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 91.224.149.41 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 82.67.62.62 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 82.64.45.50 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb ntpd[778]: 162.159.200.1 local addr 192.168.30.15 -> Aug 27 00:31:05 lms-sdb wpa_supplicant[1129]: wlan0: Trying to associate with SSID 'IOT_MUSICNOTIF' Aug 27 00:31:08 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 00:31:10 lms-sdb wpa_supplicant[1129]: wlan0: Trying to associate with SSID 'IOT_MUSICNOTIF' Aug 27 00:31:13 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 00:31:16 lms-sdb wpa_supplicant[1129]: wlan0: Trying to associate with SSID 'IOT_MUSICNOTIF' Aug 27 00:31:19 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 00:31:21 lms-sdb volumio[29767]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:21 lms-sdb volumio[29767]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 27 00:31:21 lms-sdb volumio[29767]: at doSend (dgram.js:692:16) Aug 27 00:31:21 lms-sdb volumio[29767]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 27 00:31:21 lms-sdb volumio[29767]: at afterDns (dgram.js:638:5) Aug 27 00:31:21 lms-sdb volumio[29767]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 27 00:31:21 lms-sdb volumio[29767]: errno: -101, Aug 27 00:31:21 lms-sdb volumio[29767]: code: 'ENETUNREACH', Aug 27 00:31:21 lms-sdb volumio[29767]: syscall: 'send', Aug 27 00:31:21 lms-sdb volumio[29767]: address: '255.255.255.255', Aug 27 00:31:21 lms-sdb volumio[29767]: port: 3483 Aug 27 00:31:21 lms-sdb volumio[29767]: } Aug 27 00:31:21 lms-sdb volumio[29767]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:21 lms-sdb sudo[14325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 00:30 Aug 27 00:31:21 lms-sdb sudo[14325]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:21 lms-sdb sudo[14325]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:22 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 27 00:31:22 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 27 00:31:22 lms-sdb go-librespot[25449]: time="2024-08-27T00:31:22+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Aug 27 00:31:22 lms-sdb systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:22 lms-sdb systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 27 00:31:22 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:22 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:22 lms-sdb systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 27 00:31:22 lms-sdb systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Aug 27 00:31:22 lms-sdb systemd[1]: Stopped Volumio Backend Module. Aug 27 00:31:22 lms-sdb systemd[1]: Started Volumio Backend Module. Aug 27 00:31:22 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:22 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:22 lms-sdb wpa_supplicant[1129]: wlan0: Trying to associate with SSID 'IOT_MUSICNOTIF' Aug 27 00:31:24 lms-sdb volumio[14341]: info: ------------------------------------------- Aug 27 00:31:24 lms-sdb volumio[14341]: info: ----- Volumio3 ---- Aug 27 00:31:24 lms-sdb volumio[14341]: info: ------------------------------------------- Aug 27 00:31:24 lms-sdb volumio[14341]: info: ----- System startup ---- Aug 27 00:31:24 lms-sdb volumio[14341]: info: ------------------------------------------- Aug 27 00:31:25 lms-sdb volumio[14341]: info: MYVOLUMIO Environment detected Aug 27 00:31:25 lms-sdb volumio[14341]: info: Plugin folders cleanup Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning into folder /volumio/app/plugins/ Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category audio_interface Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category miscellanea Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category music_service Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category plugins.json Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category system_controller Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category user_interface Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning into folder /data/plugins/ Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category audio_interface Aug 27 00:31:25 lms-sdb volumio[14341]: info: Scanning category music_service Aug 27 00:31:25 lms-sdb volumio[14341]: info: Plugin folders cleanup completed Aug 27 00:31:25 lms-sdb volumio[14341]: info: ------------------------------------------- Aug 27 00:31:25 lms-sdb volumio[14341]: info: ----- Core plugins startup ---- Aug 27 00:31:25 lms-sdb volumio[14341]: info: ------------------------------------------- Aug 27 00:31:25 lms-sdb volumio[14341]: info: Loading plugins from folder /volumio/app/plugins/ Aug 27 00:31:25 lms-sdb volumio[14341]: info: Adding plugin upnp to MyMusic Plugins Aug 27 00:31:25 lms-sdb volumio[14341]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 27 00:31:25 lms-sdb volumio[14341]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 27 00:31:25 lms-sdb volumio[14341]: info: Loading plugins from folder /data/plugins/ Aug 27 00:31:25 lms-sdb volumio[14341]: info: Loading plugin "system"... Aug 27 00:31:25 lms-sdb volumio[14341]: info: Loading plugin "appearance"... Aug 27 00:31:25 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 00:31:25 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="IOT_MUSICNOTIF" auth_failures=1 duration=10 reason=CONN_FAILED Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "network"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: Refreshing Cached IP Addresses Aug 27 00:31:26 lms-sdb sudo[14369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 00:31:26 lms-sdb sudo[14369]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:26 lms-sdb sudo[14371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 00:31:26 lms-sdb sudo[14371]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "services"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "alsa_controller"... Aug 27 00:31:26 lms-sdb sudo[14371]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:26 lms-sdb sudo[14369]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:26 lms-sdb sudo[14374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 27 00:31:26 lms-sdb sudo[14374]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:26 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "wizard"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "networkfs"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: Starting Udev Watcher for removable devices Aug 27 00:31:26 lms-sdb volumio[14341]: info: Ignoring mount for partition: boot Aug 27 00:31:26 lms-sdb volumio[14341]: info: Ignoring mount for partition: volumio Aug 27 00:31:26 lms-sdb volumio[14341]: info: Ignoring mount for partition: volumio_data Aug 27 00:31:26 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "volumio_command_line_client"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "upnp"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: [1724711486452] Starting Upmpd Daemon Aug 27 00:31:26 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "my_music"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "mpd"... Aug 27 00:31:26 lms-sdb volumio[14341]: info: Loading plugin "upnp_browser"... Aug 27 00:31:27 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:27] [connect] Successful connection Aug 27 00:31:27 lms-sdb volumio[14341]: info: Loading plugin "alarm-clock"... Aug 27 00:31:27 lms-sdb volumio[14341]: info: Loading plugin "airplay_emulation"... Aug 27 00:31:27 lms-sdb volumio[14341]: info: Starting Shairport Sync Aug 27 00:31:27 lms-sdb volumio[14341]: info: Loading plugin "last_100"... Aug 27 00:31:27 lms-sdb volumio[14341]: info: Loading plugin "webradio"... Aug 27 00:31:27 lms-sdb volumio[14341]: info: Loading plugin "i2s_dacs"... Aug 27 00:31:27 lms-sdb volumio[14341]: info: I2S DAC not set, start Auto-detection Aug 27 00:31:27 lms-sdb volumio[14341]: info: Loading plugin "volumiodiscovery"... Aug 27 00:31:27 lms-sdb volumio[14341]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:27 lms-sdb volumio[14341]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:27 lms-sdb volumio[14341]: *** WARNING *** For more information see Aug 27 00:31:27 lms-sdb volumio[14341]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:27 lms-sdb node[14341]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:27 lms-sdb volumio[14341]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:27 lms-sdb volumio[14341]: *** WARNING *** For more information see Aug 27 00:31:27 lms-sdb node[14341]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:27 lms-sdb node[14341]: *** WARNING *** For more information see Aug 27 00:31:27 lms-sdb node[14341]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:27 lms-sdb node[14341]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:27 lms-sdb node[14341]: *** WARNING *** For more information see Aug 27 00:31:27 lms-sdb volumio[14341]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 27 00:31:27 lms-sdb volumio[14341]: info: Discovery: Started advertising with name: LMS-SDB Aug 27 00:31:27 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:27 lms-sdb volumio[14341]: info: Loading plugin "spop"... Aug 27 00:31:28 lms-sdb volumio[14341]: info: Loading plugin "squeezelite_mc"... Aug 27 00:31:28 lms-sdb sudo[14374]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:29 lms-sdb volumio[14341]: info: Loading plugin "outputs"... Aug 27 00:31:29 lms-sdb volumio[14341]: info: Loading plugin "albumart"... Aug 27 00:31:29 lms-sdb volumio[14341]: info: Plugin example_plugin is not enabled Aug 27 00:31:29 lms-sdb volumio[14341]: info: Loading plugin "inputs"... Aug 27 00:31:29 lms-sdb volumio[14341]: info: Loading plugin "updater_comm"... Aug 27 00:31:29 lms-sdb volumio[14341]: info: Plugin mpdemulation is not enabled Aug 27 00:31:29 lms-sdb volumio[14341]: info: Loading plugin "rest_api"... Aug 27 00:31:29 lms-sdb volumio[14341]: info: Loading plugin "websocket"... Aug 27 00:31:29 lms-sdb volumio[14341]: info: Starting Socket.io Server version 2.3.0 Aug 27 00:31:29 lms-sdb volumio[14341]: info: Plugin fusiondsp is not enabled Aug 27 00:31:29 lms-sdb volumio[14341]: info: Loading i18n strings for locale fr Aug 27 00:31:29 lms-sdb volumio[14341]: Updating browse sources language Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::initPlayerControls Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:29 lms-sdb volumio[14341]: Express server listening on port 3000 Aug 27 00:31:29 lms-sdb volumio[14341]: [Metrics] WebUI: 6s 227.28ms Aug 27 00:31:29 lms-sdb volumio[14341]: Forking 3 albumart workers Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreStateMachine::resetVolumioState Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreStateMachine::getcurrentVolume Aug 27 00:31:29 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:30 lms-sdb volumio[14341]: info: Cannot read play queue from file Aug 27 00:31:30 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1724711487 101 Aug 27 00:31:30 lms-sdb volumio[14341]: 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: 1 Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreStateMachine::setRepeat null single undefined Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreStateMachine::pushState Aug 27 00:31:30 lms-sdb volumio[14341]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreStateMachine::setRandom null Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreStateMachine::pushState Aug 27 00:31:30 lms-sdb volumio[14341]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:30 lms-sdb volumio[14341]: info: Setting Device type: Raspberry PI Aug 27 00:31:30 lms-sdb volumio[14341]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreStateMachine::pushState Aug 27 00:31:30 lms-sdb volumio[14341]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreStateMachine::updateTrackBlock Aug 27 00:31:30 lms-sdb volumio[14341]: info: CorePlayQueue::getTrackBlock Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:30 lms-sdb volumio[14341]: info: Completed loading Core Plugins Aug 27 00:31:30 lms-sdb volumio[14341]: info: Preparing to generate the ALSA configuration file Aug 27 00:31:30 lms-sdb volumio[14341]: info: Asound.conf file unchanged, so no further update is needed Aug 27 00:31:30 lms-sdb volumio[14341]: info: Output device has changed, restarting MPD Aug 27 00:31:30 lms-sdb volumio[14341]: info: Output device has changed, restarting Shairport Sync Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:30 lms-sdb sudo[14462]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:31:30 lms-sdb sudo[14462]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:30 lms-sdb sudo[14462]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:30 lms-sdb sudo[14463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:31:30 lms-sdb sudo[14463]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:30 lms-sdb systemd[1]: Stopping Music Player Daemon... Aug 27 00:31:30 lms-sdb volumio[14341]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:30 lms-sdb volumio[14341]: info: ___________ START PLUGINS ___________ Aug 27 00:31:30 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:31:30 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:31:30 lms-sdb volumio[14341]: info: ControllerMpd::onStart: Initializing MPD Aug 27 00:31:30 lms-sdb volumio[14341]: info: Creating MPD Configuration file Aug 27 00:31:30 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:31:30 lms-sdb sudo[14472]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:31:30 lms-sdb sudo[14472]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:30 lms-sdb volumio[14341]: info: [1724711490803] CoreMusicLibrary::Adding element Serveurs Média Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:30 lms-sdb sudo[14472]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:30 lms-sdb sudo[14469]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 00:31:30 lms-sdb sudo[14469]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:30 lms-sdb sudo[14469]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:30 lms-sdb sudo[14475]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:31:30 lms-sdb sudo[14475]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:30 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:30 lms-sdb systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 27 00:31:30 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:31:30 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:31:30 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:31:31 lms-sdb volumio[14341]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:31 lms-sdb volumio[14341]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:31 lms-sdb volumio[14341]: info: [1724711491095] CoreMusicLibrary::Adding element Last_100 Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:31 lms-sdb volumio[14341]: info: [1724711491102] CoreMusicLibrary::Adding element Webradio Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:31 lms-sdb sudo[14482]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 00:31:31 lms-sdb sudo[14482]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:31 lms-sdb volumio[14341]: info: Initializing BBC Radios Aug 27 00:31:31 lms-sdb sudo[14482]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:31 lms-sdb volumio[14341]: Starting albumart workers Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:31 lms-sdb volumio[14341]: info: Creating Spotify config file Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:31 lms-sdb volumio[14341]: Starting albumart workers Aug 27 00:31:31 lms-sdb volumio[14341]: Starting albumart workers Aug 27 00:31:31 lms-sdb volumio[14341]: info: [squeezelite_mc] Starting proxy server... Aug 27 00:31:31 lms-sdb volumio[14341]: info: Volumio Calling Home Aug 27 00:31:31 lms-sdb volumio[14341]: info: [squeezelite_mc] Proxy server started on port 46003 Aug 27 00:31:31 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:31 lms-sdb volumio[14341]: Unhandled rejection Error: No sockets available, cannot start. Aug 27 00:31:31 lms-sdb volumio[14341]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Aug 27 00:31:31 lms-sdb volumio[14341]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Aug 27 00:31:31 lms-sdb volumio[14341]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Aug 27 00:31:31 lms-sdb volumio[14341]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Aug 27 00:31:31 lms-sdb volumio[14341]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Aug 27 00:31:31 lms-sdb volumio[14341]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Aug 27 00:31:31 lms-sdb volumio[14341]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Aug 27 00:31:31 lms-sdb volumio[14341]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Aug 27 00:31:31 lms-sdb volumio[14341]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Aug 27 00:31:31 lms-sdb volumio[14341]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Aug 27 00:31:31 lms-sdb volumio[14341]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Aug 27 00:31:31 lms-sdb volumio[14341]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Aug 27 00:31:31 lms-sdb volumio[14341]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Aug 27 00:31:31 lms-sdb volumio[14341]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Aug 27 00:31:31 lms-sdb volumio[14341]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Aug 27 00:31:31 lms-sdb volumio[14341]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 27 00:31:31 lms-sdb volumio[14341]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Aug 27 00:31:32 lms-sdb volumio[14341]: info: MPD Permissions set Aug 27 00:31:32 lms-sdb volumio[14341]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreStateMachine::pushState Aug 27 00:31:32 lms-sdb volumio[14341]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:32 lms-sdb volumio[14341]: info: Spotify config file written Aug 27 00:31:32 lms-sdb volumio[14341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb sudo[14513]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 00:31:32 lms-sdb sudo[14513]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb systemd[1]: Stopping go-librespot Daemon... Aug 27 00:31:32 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Aug 27 00:31:32 lms-sdb systemd[1]: go-librespot-daemon.service: Succeeded. Aug 27 00:31:32 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:32 lms-sdb go-librespot[14523]: Librespot-go daemon starting... Aug 27 00:31:32 lms-sdb sudo[14513]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:32 lms-sdb go-librespot[14523]: time="2024-08-27T00:31:32+02:00" level=info msg="generated new device id: c3c9546fda5df42d5ecb7eecba10d21f45ef6a83" Aug 27 00:31:32 lms-sdb go-librespot[14523]: time="2024-08-27T00:31:32+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:32 lms-sdb go-librespot[14523]: time="2024-08-27T00:31:32+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:32 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:32 lms-sdb volumio[14341]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreStateMachine::pushState Aug 27 00:31:32 lms-sdb volumio[14341]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:32 lms-sdb volumio[14341]: info: [squeezelite_mc] Server discovery started Aug 27 00:31:32 lms-sdb volumio[14341]: info: [squeezelite_mc] Player finder started Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:32 lms-sdb volumio[14341]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 27 00:31:32 lms-sdb volumio[14341]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:32 lms-sdb volumio[14341]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 27 00:31:32 lms-sdb volumio[14341]: at doSend (dgram.js:692:16) Aug 27 00:31:32 lms-sdb volumio[14341]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 27 00:31:32 lms-sdb volumio[14341]: at afterDns (dgram.js:638:5) Aug 27 00:31:32 lms-sdb volumio[14341]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 27 00:31:32 lms-sdb volumio[14341]: errno: -101, Aug 27 00:31:32 lms-sdb volumio[14341]: code: 'ENETUNREACH', Aug 27 00:31:32 lms-sdb volumio[14341]: syscall: 'send', Aug 27 00:31:32 lms-sdb volumio[14341]: address: '255.255.255.255', Aug 27 00:31:32 lms-sdb volumio[14341]: port: 3483 Aug 27 00:31:32 lms-sdb volumio[14341]: } Aug 27 00:31:32 lms-sdb volumio[14341]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:33 lms-sdb sudo[14558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 00:30 Aug 27 00:31:33 lms-sdb sudo[14558]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:33 lms-sdb sudo[14558]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:33 lms-sdb mpd[14487]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 00:31:33 lms-sdb mpd[14487]: output: No 'audio_output' defined in config file Aug 27 00:31:33 lms-sdb mpd[14487]: output: Successfully detected a sndio audio device Aug 27 00:31:33 lms-sdb mpd[14487]: zeroconf: No global port, disabling zeroconf Aug 27 00:31:33 lms-sdb systemd[1]: Started Music Player Daemon. Aug 27 00:31:33 lms-sdb sudo[14463]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:33 lms-sdb sudo[14475]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:33 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:33] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 27 00:31:33 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:33] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 27 00:31:33 lms-sdb systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:33 lms-sdb systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 27 00:31:33 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:33 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:33 lms-sdb systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 27 00:31:33 lms-sdb systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Aug 27 00:31:33 lms-sdb systemd[1]: Stopped Volumio Backend Module. Aug 27 00:31:33 lms-sdb systemd[1]: Started Volumio Backend Module. Aug 27 00:31:33 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:33 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:35 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:35 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 27 00:31:35 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:35 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:35 lms-sdb go-librespot[14595]: Librespot-go daemon starting... Aug 27 00:31:35 lms-sdb go-librespot[14595]: time="2024-08-27T00:31:35+02:00" level=info msg="generated new device id: 55611b924bc3efb74f46253dec78caa67d2c67c1" Aug 27 00:31:35 lms-sdb go-librespot[14595]: time="2024-08-27T00:31:35+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:35 lms-sdb go-librespot[14595]: time="2024-08-27T00:31:35+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:35 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:35 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:35 lms-sdb volumio[14574]: info: ------------------------------------------- Aug 27 00:31:35 lms-sdb volumio[14574]: info: ----- Volumio3 ---- Aug 27 00:31:35 lms-sdb volumio[14574]: info: ------------------------------------------- Aug 27 00:31:35 lms-sdb volumio[14574]: info: ----- System startup ---- Aug 27 00:31:35 lms-sdb volumio[14574]: info: ------------------------------------------- Aug 27 00:31:35 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="IOT_MUSICNOTIF" Aug 27 00:31:35 lms-sdb wpa_supplicant[1129]: wlan0: Trying to associate with SSID 'IOT_MUSICNOTIF' Aug 27 00:31:36 lms-sdb volumio[14574]: info: MYVOLUMIO Environment detected Aug 27 00:31:36 lms-sdb volumio[14574]: info: Plugin folders cleanup Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning into folder /volumio/app/plugins/ Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category audio_interface Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category miscellanea Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category music_service Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category plugins.json Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category system_controller Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category user_interface Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning into folder /data/plugins/ Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category audio_interface Aug 27 00:31:36 lms-sdb volumio[14574]: info: Scanning category music_service Aug 27 00:31:36 lms-sdb volumio[14574]: info: Plugin folders cleanup completed Aug 27 00:31:36 lms-sdb volumio[14574]: info: ------------------------------------------- Aug 27 00:31:36 lms-sdb volumio[14574]: info: ----- Core plugins startup ---- Aug 27 00:31:36 lms-sdb volumio[14574]: info: ------------------------------------------- Aug 27 00:31:36 lms-sdb volumio[14574]: info: Loading plugins from folder /volumio/app/plugins/ Aug 27 00:31:36 lms-sdb volumio[14574]: info: Adding plugin upnp to MyMusic Plugins Aug 27 00:31:36 lms-sdb volumio[14574]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 27 00:31:36 lms-sdb volumio[14574]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 27 00:31:36 lms-sdb volumio[14574]: info: Loading plugins from folder /data/plugins/ Aug 27 00:31:36 lms-sdb volumio[14574]: info: Loading plugin "system"... Aug 27 00:31:36 lms-sdb volumio[14574]: info: Loading plugin "appearance"... Aug 27 00:31:37 lms-sdb volumio[14574]: info: Loading plugin "network"... Aug 27 00:31:37 lms-sdb volumio[14574]: info: Refreshing Cached IP Addresses Aug 27 00:31:37 lms-sdb sudo[14608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 00:31:37 lms-sdb sudo[14608]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:37 lms-sdb sudo[14608]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:37 lms-sdb sudo[14610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 00:31:37 lms-sdb sudo[14610]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:37 lms-sdb volumio[14574]: info: Loading plugin "services"... Aug 27 00:31:37 lms-sdb volumio[14574]: info: Loading plugin "alsa_controller"... Aug 27 00:31:37 lms-sdb sudo[14610]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:37 lms-sdb sudo[14613]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 27 00:31:37 lms-sdb sudo[14613]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:37 lms-sdb sudo[14613]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:37 lms-sdb kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3) Aug 27 00:31:37 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:37 lms-sdb volumio[14574]: info: Loading plugin "wizard"... Aug 27 00:31:37 lms-sdb volumio[14574]: info: Loading plugin "networkfs"... Aug 27 00:31:37 lms-sdb volumio[14574]: info: Starting Udev Watcher for removable devices Aug 27 00:31:37 lms-sdb volumio[14574]: info: Ignoring mount for partition: boot Aug 27 00:31:37 lms-sdb volumio[14574]: info: Ignoring mount for partition: volumio Aug 27 00:31:37 lms-sdb volumio[14574]: info: Ignoring mount for partition: volumio_data Aug 27 00:31:37 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:37 lms-sdb volumio[14574]: info: Loading plugin "volumio_command_line_client"... Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "upnp"... Aug 27 00:31:38 lms-sdb volumio[14574]: info: [1724711498011] Starting Upmpd Daemon Aug 27 00:31:38 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "my_music"... Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "mpd"... Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "upnp_browser"... Aug 27 00:31:38 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Aug 27 00:31:38 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="IOT_MUSICNOTIF" auth_failures=2 duration=23 reason=CONN_FAILED Aug 27 00:31:38 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:38] [connect] Successful connection Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "alarm-clock"... Aug 27 00:31:38 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:38 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "airplay_emulation"... Aug 27 00:31:38 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:38 lms-sdb volumio[14574]: info: Starting Shairport Sync Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "last_100"... Aug 27 00:31:38 lms-sdb volumio[14574]: info: Loading plugin "webradio"... Aug 27 00:31:38 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:38 lms-sdb go-librespot[14620]: Librespot-go daemon starting... Aug 27 00:31:38 lms-sdb go-librespot[14620]: time="2024-08-27T00:31:38+02:00" level=info msg="generated new device id: d6a57412649a2cf4f31a22ae0fdf73a3d71d3380" Aug 27 00:31:38 lms-sdb go-librespot[14620]: time="2024-08-27T00:31:38+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:38 lms-sdb go-librespot[14620]: time="2024-08-27T00:31:38+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:38 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:38 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:39 lms-sdb volumio[14574]: info: Loading plugin "i2s_dacs"... Aug 27 00:31:39 lms-sdb volumio[14574]: info: I2S DAC not set, start Auto-detection Aug 27 00:31:39 lms-sdb volumio[14574]: info: Loading plugin "volumiodiscovery"... Aug 27 00:31:39 lms-sdb volumio[14574]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:39 lms-sdb volumio[14574]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:39 lms-sdb volumio[14574]: *** WARNING *** For more information see Aug 27 00:31:39 lms-sdb node[14574]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:39 lms-sdb volumio[14574]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:39 lms-sdb volumio[14574]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:39 lms-sdb volumio[14574]: *** WARNING *** For more information see Aug 27 00:31:39 lms-sdb node[14574]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:39 lms-sdb node[14574]: *** WARNING *** For more information see Aug 27 00:31:39 lms-sdb node[14574]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:39 lms-sdb node[14574]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:39 lms-sdb node[14574]: *** WARNING *** For more information see Aug 27 00:31:39 lms-sdb volumio[14574]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 27 00:31:39 lms-sdb volumio[14574]: info: Discovery: Started advertising with name: LMS-SDB Aug 27 00:31:39 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:39 lms-sdb volumio[14574]: info: Loading plugin "spop"... Aug 27 00:31:40 lms-sdb volumio[14574]: info: Loading plugin "squeezelite_mc"... Aug 27 00:31:40 lms-sdb volumio[14574]: info: Loading plugin "outputs"... Aug 27 00:31:40 lms-sdb volumio[14574]: info: Loading plugin "albumart"... Aug 27 00:31:41 lms-sdb volumio[14574]: info: Plugin example_plugin is not enabled Aug 27 00:31:41 lms-sdb volumio[14574]: info: Loading plugin "inputs"... Aug 27 00:31:41 lms-sdb volumio[14574]: info: Loading plugin "updater_comm"... Aug 27 00:31:41 lms-sdb volumio[14574]: info: Plugin mpdemulation is not enabled Aug 27 00:31:41 lms-sdb volumio[14574]: info: Loading plugin "rest_api"... Aug 27 00:31:41 lms-sdb volumio[14574]: info: Loading plugin "websocket"... Aug 27 00:31:41 lms-sdb volumio[14574]: info: Starting Socket.io Server version 2.3.0 Aug 27 00:31:41 lms-sdb volumio[14574]: info: Plugin fusiondsp is not enabled Aug 27 00:31:41 lms-sdb volumio[14574]: info: Loading i18n strings for locale fr Aug 27 00:31:41 lms-sdb volumio[14574]: Updating browse sources language Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::initPlayerControls Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: Forking 3 albumart workers Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: Express server listening on port 3000 Aug 27 00:31:41 lms-sdb volumio[14574]: [Metrics] WebUI: 6s 290.14ms Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreStateMachine::resetVolumioState Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreStateMachine::getcurrentVolume Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:41 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:41 lms-sdb volumio[14574]: info: Cannot read play queue from file Aug 27 00:31:41 lms-sdb volumio[14574]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 27 00:31:41 lms-sdb volumio[14574]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Aug 27 00:31:41 lms-sdb volumio[14574]: info: Cannot use regular scanning, forcing with ap-force Aug 27 00:31:41 lms-sdb sudo[14662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 27 00:31:41 lms-sdb sudo[14662]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:42 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:42 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 27 00:31:42 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:42 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:42 lms-sdb go-librespot[14664]: Librespot-go daemon starting... Aug 27 00:31:42 lms-sdb go-librespot[14664]: time="2024-08-27T00:31:42+02:00" level=info msg="generated new device id: bd251890def56943f59428826e76cb421a6b7fbb" Aug 27 00:31:42 lms-sdb go-librespot[14664]: time="2024-08-27T00:31:42+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:42 lms-sdb go-librespot[14664]: time="2024-08-27T00:31:42+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:42 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:42 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:42 lms-sdb volumio[14574]: Starting albumart workers Aug 27 00:31:42 lms-sdb volumio[14574]: Starting albumart workers Aug 27 00:31:42 lms-sdb volumio[14574]: Starting albumart workers Aug 27 00:31:44 lms-sdb sudo[14662]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreStateMachine::setRepeat null single undefined Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreStateMachine::pushState Aug 27 00:31:44 lms-sdb volumio[14574]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreStateMachine::setRandom null Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreStateMachine::pushState Aug 27 00:31:44 lms-sdb volumio[14574]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:44 lms-sdb volumio[14574]: info: Setting Device type: Raspberry PI Aug 27 00:31:44 lms-sdb volumio[14574]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreStateMachine::pushState Aug 27 00:31:44 lms-sdb volumio[14574]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreStateMachine::updateTrackBlock Aug 27 00:31:44 lms-sdb volumio[14574]: info: CorePlayQueue::getTrackBlock Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:44 lms-sdb volumio[14574]: info: Completed loading Core Plugins Aug 27 00:31:44 lms-sdb volumio[14574]: info: Preparing to generate the ALSA configuration file Aug 27 00:31:44 lms-sdb volumio[14574]: info: Asound.conf file unchanged, so no further update is needed Aug 27 00:31:44 lms-sdb volumio[14574]: info: Output device has changed, restarting MPD Aug 27 00:31:44 lms-sdb sudo[14704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:31:44 lms-sdb sudo[14704]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:44 lms-sdb volumio[14574]: info: Output device has changed, restarting Shairport Sync Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:44 lms-sdb sudo[14704]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:44 lms-sdb sudo[14706]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:31:44 lms-sdb sudo[14706]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:44 lms-sdb systemd[1]: Stopping Music Player Daemon... Aug 27 00:31:44 lms-sdb volumio[14574]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:44 lms-sdb volumio[14574]: info: ___________ START PLUGINS ___________ Aug 27 00:31:44 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:31:44 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:31:44 lms-sdb volumio[14574]: info: ControllerMpd::onStart: Initializing MPD Aug 27 00:31:44 lms-sdb volumio[14574]: info: Creating MPD Configuration file Aug 27 00:31:44 lms-sdb sudo[14714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:31:44 lms-sdb sudo[14714]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:44 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:44 lms-sdb volumio[14574]: info: [1724711504756] CoreMusicLibrary::Adding element Serveurs Média Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:44 lms-sdb sudo[14714]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:44 lms-sdb sudo[14716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:31:44 lms-sdb sudo[14716]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:44 lms-sdb systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 27 00:31:44 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:31:44 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:31:44 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:31:44 lms-sdb volumio[14574]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:44 lms-sdb volumio[14574]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:44 lms-sdb volumio[14574]: info: [1724711504896] CoreMusicLibrary::Adding element Last_100 Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:44 lms-sdb volumio[14574]: info: [1724711504900] CoreMusicLibrary::Adding element Webradio Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:44 lms-sdb volumio[14574]: info: Initializing BBC Radios Aug 27 00:31:44 lms-sdb sudo[14722]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 00:31:44 lms-sdb sudo[14722]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:44 lms-sdb sudo[14722]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:44 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: Creating Spotify config file Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: [squeezelite_mc] Starting proxy server... Aug 27 00:31:45 lms-sdb volumio[14574]: info: Volumio Calling Home Aug 27 00:31:45 lms-sdb volumio[14574]: info: [squeezelite_mc] Proxy server started on port 42331 Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:45 lms-sdb volumio[14574]: Unhandled rejection Error: No sockets available, cannot start. Aug 27 00:31:45 lms-sdb volumio[14574]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Aug 27 00:31:45 lms-sdb volumio[14574]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Aug 27 00:31:45 lms-sdb volumio[14574]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Aug 27 00:31:45 lms-sdb volumio[14574]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Aug 27 00:31:45 lms-sdb volumio[14574]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Aug 27 00:31:45 lms-sdb volumio[14574]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Aug 27 00:31:45 lms-sdb volumio[14574]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Aug 27 00:31:45 lms-sdb volumio[14574]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Aug 27 00:31:45 lms-sdb volumio[14574]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Aug 27 00:31:45 lms-sdb volumio[14574]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Aug 27 00:31:45 lms-sdb volumio[14574]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Aug 27 00:31:45 lms-sdb volumio[14574]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Aug 27 00:31:45 lms-sdb volumio[14574]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Aug 27 00:31:45 lms-sdb volumio[14574]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Aug 27 00:31:45 lms-sdb volumio[14574]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Aug 27 00:31:45 lms-sdb volumio[14574]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 27 00:31:45 lms-sdb volumio[14574]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Aug 27 00:31:45 lms-sdb volumio[14574]: info: MPD Permissions set Aug 27 00:31:45 lms-sdb volumio[14574]: info: MPD Permissions set Aug 27 00:31:45 lms-sdb volumio[14574]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreStateMachine::pushState Aug 27 00:31:45 lms-sdb volumio[14574]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:45 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:45 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 27 00:31:45 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:45 lms-sdb volumio[14574]: info: Spotify config file written Aug 27 00:31:45 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:45 lms-sdb go-librespot[14743]: Librespot-go daemon starting... Aug 27 00:31:45 lms-sdb sudo[14746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 00:31:45 lms-sdb sudo[14746]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:45 lms-sdb volumio[14574]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 27 00:31:45 lms-sdb go-librespot[14743]: time="2024-08-27T00:31:45+02:00" level=info msg="generated new device id: eee59436df5fc9b394e5a36ad1efe06b54d47260" Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb go-librespot[14743]: time="2024-08-27T00:31:45+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb go-librespot[14743]: time="2024-08-27T00:31:45+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:45 lms-sdb systemd[1]: Stopping go-librespot Daemon... Aug 27 00:31:45 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Aug 27 00:31:45 lms-sdb systemd[1]: go-librespot-daemon.service: Succeeded. Aug 27 00:31:45 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb go-librespot[14758]: Librespot-go daemon starting... Aug 27 00:31:45 lms-sdb sudo[14746]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:45 lms-sdb go-librespot[14758]: time="2024-08-27T00:31:45+02:00" level=info msg="generated new device id: 53069919c1ffd3db11dbab06e541815f1fd1e424" Aug 27 00:31:45 lms-sdb go-librespot[14758]: time="2024-08-27T00:31:45+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:45 lms-sdb go-librespot[14758]: time="2024-08-27T00:31:45+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:45 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:45 lms-sdb volumio[14574]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreStateMachine::pushState Aug 27 00:31:45 lms-sdb volumio[14574]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:45 lms-sdb volumio[14574]: info: [squeezelite_mc] Server discovery started Aug 27 00:31:45 lms-sdb volumio[14574]: info: [squeezelite_mc] Player finder started Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:45 lms-sdb volumio[14574]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 27 00:31:45 lms-sdb volumio[14574]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:45 lms-sdb volumio[14574]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 27 00:31:45 lms-sdb volumio[14574]: at doSend (dgram.js:692:16) Aug 27 00:31:45 lms-sdb volumio[14574]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 27 00:31:45 lms-sdb volumio[14574]: at afterDns (dgram.js:638:5) Aug 27 00:31:45 lms-sdb volumio[14574]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 27 00:31:45 lms-sdb volumio[14574]: errno: -101, Aug 27 00:31:45 lms-sdb volumio[14574]: code: 'ENETUNREACH', Aug 27 00:31:45 lms-sdb volumio[14574]: syscall: 'send', Aug 27 00:31:45 lms-sdb volumio[14574]: address: '255.255.255.255', Aug 27 00:31:45 lms-sdb volumio[14574]: port: 3483 Aug 27 00:31:45 lms-sdb volumio[14574]: } Aug 27 00:31:45 lms-sdb volumio[14574]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:46 lms-sdb sudo[14780]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 00:30 Aug 27 00:31:46 lms-sdb sudo[14780]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:46 lms-sdb sudo[14780]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:46 lms-sdb systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:46 lms-sdb sudo[14706]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:46 lms-sdb sudo[14716]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:46 lms-sdb systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 27 00:31:46 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:46 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:46 lms-sdb mpd[14734]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 00:31:46 lms-sdb mpd[14734]: output: No 'audio_output' defined in config file Aug 27 00:31:46 lms-sdb mpd[14734]: output: Successfully detected a sndio audio device Aug 27 00:31:46 lms-sdb mpd[14734]: zeroconf: No global port, disabling zeroconf Aug 27 00:31:46 lms-sdb systemd[1]: Started Music Player Daemon. Aug 27 00:31:46 lms-sdb systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 27 00:31:46 lms-sdb systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Aug 27 00:31:46 lms-sdb systemd[1]: Stopped Volumio Backend Module. Aug 27 00:31:46 lms-sdb systemd[1]: Started Volumio Backend Module. Aug 27 00:31:46 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:46 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:48 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:48 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 27 00:31:48 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:48 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:48 lms-sdb go-librespot[14816]: Librespot-go daemon starting... Aug 27 00:31:48 lms-sdb go-librespot[14816]: time="2024-08-27T00:31:48+02:00" level=info msg="generated new device id: 982b2db38240180bd92985aa473a3aa4d831b12a" Aug 27 00:31:48 lms-sdb go-librespot[14816]: time="2024-08-27T00:31:48+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:48 lms-sdb go-librespot[14816]: time="2024-08-27T00:31:48+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:48 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:48 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:48 lms-sdb volumio[14795]: info: ------------------------------------------- Aug 27 00:31:48 lms-sdb volumio[14795]: info: ----- Volumio3 ---- Aug 27 00:31:48 lms-sdb volumio[14795]: info: ------------------------------------------- Aug 27 00:31:48 lms-sdb volumio[14795]: info: ----- System startup ---- Aug 27 00:31:48 lms-sdb volumio[14795]: info: ------------------------------------------- Aug 27 00:31:49 lms-sdb volumio[14795]: info: MYVOLUMIO Environment detected Aug 27 00:31:49 lms-sdb volumio[14795]: info: Plugin folders cleanup Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning into folder /volumio/app/plugins/ Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category audio_interface Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category miscellanea Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category music_service Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category plugins.json Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category system_controller Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category user_interface Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning into folder /data/plugins/ Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category audio_interface Aug 27 00:31:49 lms-sdb volumio[14795]: info: Scanning category music_service Aug 27 00:31:49 lms-sdb volumio[14795]: info: Plugin folders cleanup completed Aug 27 00:31:49 lms-sdb volumio[14795]: info: ------------------------------------------- Aug 27 00:31:49 lms-sdb volumio[14795]: info: ----- Core plugins startup ---- Aug 27 00:31:49 lms-sdb volumio[14795]: info: ------------------------------------------- Aug 27 00:31:49 lms-sdb volumio[14795]: info: Loading plugins from folder /volumio/app/plugins/ Aug 27 00:31:49 lms-sdb volumio[14795]: info: Adding plugin upnp to MyMusic Plugins Aug 27 00:31:49 lms-sdb volumio[14795]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 27 00:31:49 lms-sdb volumio[14795]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 27 00:31:49 lms-sdb volumio[14795]: info: Loading plugins from folder /data/plugins/ Aug 27 00:31:49 lms-sdb volumio[14795]: info: Loading plugin "system"... Aug 27 00:31:49 lms-sdb volumio[14795]: info: Loading plugin "appearance"... Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "network"... Aug 27 00:31:50 lms-sdb volumio[14795]: info: Refreshing Cached IP Addresses Aug 27 00:31:50 lms-sdb sudo[14830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 00:31:50 lms-sdb sudo[14830]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:50 lms-sdb sudo[14830]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "services"... Aug 27 00:31:50 lms-sdb sudo[14832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 00:31:50 lms-sdb sudo[14832]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "alsa_controller"... Aug 27 00:31:50 lms-sdb sudo[14832]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:50 lms-sdb sudo[14835]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 27 00:31:50 lms-sdb sudo[14835]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:50 lms-sdb sudo[14835]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:50 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "wizard"... Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "networkfs"... Aug 27 00:31:50 lms-sdb volumio[14795]: info: Starting Udev Watcher for removable devices Aug 27 00:31:50 lms-sdb volumio[14795]: info: Ignoring mount for partition: boot Aug 27 00:31:50 lms-sdb volumio[14795]: info: Ignoring mount for partition: volumio Aug 27 00:31:50 lms-sdb volumio[14795]: info: Ignoring mount for partition: volumio_data Aug 27 00:31:50 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "volumio_command_line_client"... Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "upnp"... Aug 27 00:31:50 lms-sdb volumio[14795]: info: [1724711510842] Starting Upmpd Daemon Aug 27 00:31:50 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "my_music"... Aug 27 00:31:50 lms-sdb volumio[14795]: info: Loading plugin "mpd"... Aug 27 00:31:51 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:31:51] [connect] Successful connection Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "upnp_browser"... Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "alarm-clock"... Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "airplay_emulation"... Aug 27 00:31:51 lms-sdb volumio[14795]: info: Starting Shairport Sync Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "last_100"... Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "webradio"... Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "i2s_dacs"... Aug 27 00:31:51 lms-sdb volumio[14795]: info: I2S DAC not set, start Auto-detection Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "volumiodiscovery"... Aug 27 00:31:51 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:51 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 27 00:31:51 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:51 lms-sdb volumio[14795]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:51 lms-sdb volumio[14795]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:51 lms-sdb volumio[14795]: *** WARNING *** For more information see Aug 27 00:31:51 lms-sdb node[14795]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:51 lms-sdb volumio[14795]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:51 lms-sdb volumio[14795]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:51 lms-sdb volumio[14795]: *** WARNING *** For more information see Aug 27 00:31:51 lms-sdb node[14795]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:51 lms-sdb node[14795]: *** WARNING *** For more information see Aug 27 00:31:51 lms-sdb node[14795]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:31:51 lms-sdb node[14795]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:31:51 lms-sdb node[14795]: *** WARNING *** For more information see Aug 27 00:31:51 lms-sdb volumio[14795]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 27 00:31:51 lms-sdb volumio[14795]: info: Discovery: Started advertising with name: LMS-SDB Aug 27 00:31:51 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:51 lms-sdb go-librespot[14842]: Librespot-go daemon starting... Aug 27 00:31:51 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:31:51 lms-sdb volumio[14795]: info: Loading plugin "spop"... Aug 27 00:31:51 lms-sdb go-librespot[14842]: time="2024-08-27T00:31:51+02:00" level=info msg="generated new device id: 5638c774954c199a0bad57d0808dd9ef74c3a139" Aug 27 00:31:51 lms-sdb go-librespot[14842]: time="2024-08-27T00:31:51+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:51 lms-sdb go-librespot[14842]: time="2024-08-27T00:31:51+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:51 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:51 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:53 lms-sdb volumio[14795]: info: Loading plugin "squeezelite_mc"... Aug 27 00:31:53 lms-sdb volumio[14795]: info: Loading plugin "outputs"... Aug 27 00:31:53 lms-sdb volumio[14795]: info: Loading plugin "albumart"... Aug 27 00:31:53 lms-sdb volumio[14795]: info: Plugin example_plugin is not enabled Aug 27 00:31:53 lms-sdb volumio[14795]: info: Loading plugin "inputs"... Aug 27 00:31:53 lms-sdb volumio[14795]: info: Loading plugin "updater_comm"... Aug 27 00:31:54 lms-sdb volumio[14795]: info: Plugin mpdemulation is not enabled Aug 27 00:31:54 lms-sdb volumio[14795]: info: Loading plugin "rest_api"... Aug 27 00:31:54 lms-sdb volumio[14795]: info: Loading plugin "websocket"... Aug 27 00:31:54 lms-sdb volumio[14795]: info: Starting Socket.io Server version 2.3.0 Aug 27 00:31:54 lms-sdb volumio[14795]: info: Plugin fusiondsp is not enabled Aug 27 00:31:54 lms-sdb volumio[14795]: info: Loading i18n strings for locale fr Aug 27 00:31:54 lms-sdb volumio[14795]: Updating browse sources language Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::initPlayerControls Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: Express server listening on port 3000 Aug 27 00:31:54 lms-sdb volumio[14795]: [Metrics] WebUI: 6s 188.31ms Aug 27 00:31:54 lms-sdb volumio[14795]: Forking 3 albumart workers Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreStateMachine::resetVolumioState Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreStateMachine::getcurrentVolume Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:54 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:54 lms-sdb volumio[14795]: info: Cannot read play queue from file Aug 27 00:31:54 lms-sdb volumio[14795]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 27 00:31:54 lms-sdb volumio[14795]: wlan0 Interface doesn't support scanning : Device or resource busy Aug 27 00:31:54 lms-sdb volumio[14795]: info: Cannot use regular scanning, forcing with ap-force Aug 27 00:31:54 lms-sdb sudo[14886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 27 00:31:54 lms-sdb sudo[14886]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:55 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:55 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 27 00:31:55 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:55 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:55 lms-sdb go-librespot[14888]: Librespot-go daemon starting... Aug 27 00:31:55 lms-sdb go-librespot[14888]: time="2024-08-27T00:31:55+02:00" level=info msg="generated new device id: 2c86f33abfbf21fcc3c19c66d8004762f5dc39d7" Aug 27 00:31:55 lms-sdb go-librespot[14888]: time="2024-08-27T00:31:55+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:55 lms-sdb go-librespot[14888]: time="2024-08-27T00:31:55+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:55 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:55 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:55 lms-sdb volumio[14795]: Starting albumart workers Aug 27 00:31:55 lms-sdb volumio[14795]: Starting albumart workers Aug 27 00:31:55 lms-sdb volumio[14795]: Starting albumart workers Aug 27 00:31:57 lms-sdb sudo[14886]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:57 lms-sdb volumio[14795]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreStateMachine::pushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreStateMachine::updateTrackBlock Aug 27 00:31:57 lms-sdb volumio[14795]: info: CorePlayQueue::getTrackBlock Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreStateMachine::setRepeat null single undefined Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreStateMachine::pushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreStateMachine::setRandom null Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreStateMachine::pushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: Setting Device type: Raspberry PI Aug 27 00:31:57 lms-sdb volumio[14795]: info: Completed loading Core Plugins Aug 27 00:31:57 lms-sdb volumio[14795]: info: Preparing to generate the ALSA configuration file Aug 27 00:31:57 lms-sdb volumio[14795]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreStateMachine::pushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:57 lms-sdb volumio[14795]: info: Asound.conf file unchanged, so no further update is needed Aug 27 00:31:57 lms-sdb volumio[14795]: info: Output device has changed, restarting MPD Aug 27 00:31:57 lms-sdb sudo[14926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:31:57 lms-sdb sudo[14926]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:57 lms-sdb volumio[14795]: info: Output device has changed, restarting Shairport Sync Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:57 lms-sdb sudo[14926]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:57 lms-sdb sudo[14929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:31:57 lms-sdb sudo[14929]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:57 lms-sdb systemd[1]: Stopping Music Player Daemon... Aug 27 00:31:57 lms-sdb volumio[14795]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:57 lms-sdb volumio[14795]: info: ___________ START PLUGINS ___________ Aug 27 00:31:57 lms-sdb volumio[14795]: info: ControllerMpd::onStart: Initializing MPD Aug 27 00:31:57 lms-sdb volumio[14795]: info: Creating MPD Configuration file Aug 27 00:31:57 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:31:57 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:31:57 lms-sdb sudo[14936]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:31:57 lms-sdb sudo[14936]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:57 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:57 lms-sdb volumio[14795]: info: [1724711517625] CoreMusicLibrary::Adding element Serveurs Média Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:57 lms-sdb sudo[14936]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:57 lms-sdb sudo[14939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:31:57 lms-sdb sudo[14939]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:57 lms-sdb systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 27 00:31:57 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:31:57 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:31:57 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:31:57 lms-sdb volumio[14795]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:57 lms-sdb volumio[14795]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:57 lms-sdb volumio[14795]: info: [1724711517759] CoreMusicLibrary::Adding element Last_100 Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:31:57 lms-sdb volumio[14795]: info: [1724711517763] CoreMusicLibrary::Adding element Webradio Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:57 lms-sdb volumio[14795]: info: Initializing BBC Radios Aug 27 00:31:57 lms-sdb sudo[14947]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 00:31:57 lms-sdb sudo[14947]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:57 lms-sdb sudo[14947]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:57 lms-sdb volumio[14795]: info: Creating Spotify config file Aug 27 00:31:57 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:57 lms-sdb volumio[14795]: info: [squeezelite_mc] Starting proxy server... Aug 27 00:31:58 lms-sdb volumio[14795]: info: Volumio Calling Home Aug 27 00:31:58 lms-sdb volumio[14795]: info: [squeezelite_mc] Proxy server started on port 37825 Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:31:58 lms-sdb volumio[14795]: Unhandled rejection Error: No sockets available, cannot start. Aug 27 00:31:58 lms-sdb volumio[14795]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Aug 27 00:31:58 lms-sdb volumio[14795]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Aug 27 00:31:58 lms-sdb volumio[14795]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Aug 27 00:31:58 lms-sdb volumio[14795]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Aug 27 00:31:58 lms-sdb volumio[14795]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Aug 27 00:31:58 lms-sdb volumio[14795]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Aug 27 00:31:58 lms-sdb volumio[14795]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Aug 27 00:31:58 lms-sdb volumio[14795]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Aug 27 00:31:58 lms-sdb volumio[14795]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Aug 27 00:31:58 lms-sdb volumio[14795]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Aug 27 00:31:58 lms-sdb volumio[14795]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Aug 27 00:31:58 lms-sdb volumio[14795]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Aug 27 00:31:58 lms-sdb volumio[14795]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Aug 27 00:31:58 lms-sdb volumio[14795]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Aug 27 00:31:58 lms-sdb volumio[14795]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Aug 27 00:31:58 lms-sdb volumio[14795]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 27 00:31:58 lms-sdb volumio[14795]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Aug 27 00:31:58 lms-sdb volumio[14795]: info: MPD Permissions set Aug 27 00:31:58 lms-sdb volumio[14795]: info: MPD Permissions set Aug 27 00:31:58 lms-sdb volumio[14795]: info: Spotify config file written Aug 27 00:31:58 lms-sdb sudo[14969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 00:31:58 lms-sdb sudo[14969]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:58 lms-sdb volumio[14795]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:31:58 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 27 00:31:58 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:58 lms-sdb go-librespot[14972]: Librespot-go daemon starting... Aug 27 00:31:58 lms-sdb systemd[1]: Stopping go-librespot Daemon... Aug 27 00:31:58 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Aug 27 00:31:58 lms-sdb systemd[1]: go-librespot-daemon.service: Succeeded. Aug 27 00:31:58 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:31:58 lms-sdb volumio[14795]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:31:58 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreStateMachine::pushState Aug 27 00:31:58 lms-sdb volumio[14795]: info: CorePlayQueue::getTrack 0 Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::volumioPushState Aug 27 00:31:58 lms-sdb go-librespot[14981]: Librespot-go daemon starting... Aug 27 00:31:58 lms-sdb sudo[14969]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:58 lms-sdb volumio[14795]: info: [squeezelite_mc] Server discovery started Aug 27 00:31:58 lms-sdb volumio[14795]: info: [squeezelite_mc] Player finder started Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:31:58 lms-sdb volumio[14795]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 27 00:31:58 lms-sdb go-librespot[14981]: time="2024-08-27T00:31:58+02:00" level=info msg="generated new device id: 230e45e99d8ed9eb5a7f943fe922a5c408730e2f" Aug 27 00:31:58 lms-sdb go-librespot[14981]: time="2024-08-27T00:31:58+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:31:58 lms-sdb go-librespot[14981]: time="2024-08-27T00:31:58+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:31:58 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:58 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:31:58 lms-sdb volumio[14795]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:58 lms-sdb volumio[14795]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 27 00:31:58 lms-sdb volumio[14795]: at doSend (dgram.js:692:16) Aug 27 00:31:58 lms-sdb volumio[14795]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 27 00:31:58 lms-sdb volumio[14795]: at afterDns (dgram.js:638:5) Aug 27 00:31:58 lms-sdb volumio[14795]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 27 00:31:58 lms-sdb volumio[14795]: errno: -101, Aug 27 00:31:58 lms-sdb volumio[14795]: code: 'ENETUNREACH', Aug 27 00:31:58 lms-sdb volumio[14795]: syscall: 'send', Aug 27 00:31:58 lms-sdb volumio[14795]: address: '255.255.255.255', Aug 27 00:31:58 lms-sdb volumio[14795]: port: 3483 Aug 27 00:31:58 lms-sdb volumio[14795]: } Aug 27 00:31:58 lms-sdb volumio[14795]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:31:59 lms-sdb sudo[14999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 00:30 Aug 27 00:31:59 lms-sdb sudo[14999]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:31:59 lms-sdb sudo[14999]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:59 lms-sdb systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:31:59 lms-sdb sudo[14929]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:59 lms-sdb sudo[14939]: pam_unix(sudo:session): session closed for user root Aug 27 00:31:59 lms-sdb systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 27 00:31:59 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:59 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:59 lms-sdb systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 27 00:31:59 lms-sdb systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5. Aug 27 00:31:59 lms-sdb systemd[1]: Stopped Volumio Backend Module. Aug 27 00:31:59 lms-sdb systemd[1]: Started Volumio Backend Module. Aug 27 00:31:59 lms-sdb systemd[1]: Started dynamicswap service. Aug 27 00:31:59 lms-sdb systemd[1]: dynamicswap.service: Succeeded. Aug 27 00:31:59 lms-sdb mpd[14959]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 27 00:31:59 lms-sdb mpd[14959]: output: No 'audio_output' defined in config file Aug 27 00:31:59 lms-sdb mpd[14959]: output: Successfully detected a sndio audio device Aug 27 00:31:59 lms-sdb mpd[14959]: zeroconf: No global port, disabling zeroconf Aug 27 00:31:59 lms-sdb systemd[1]: Started Music Player Daemon. Aug 27 00:32:01 lms-sdb volumio[15013]: info: ------------------------------------------- Aug 27 00:32:01 lms-sdb volumio[15013]: info: ----- Volumio3 ---- Aug 27 00:32:01 lms-sdb volumio[15013]: info: ------------------------------------------- Aug 27 00:32:01 lms-sdb volumio[15013]: info: ----- System startup ---- Aug 27 00:32:01 lms-sdb volumio[15013]: info: ------------------------------------------- Aug 27 00:32:01 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:32:01 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 27 00:32:01 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:32:01 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:32:01 lms-sdb go-librespot[15036]: Librespot-go daemon starting... Aug 27 00:32:01 lms-sdb go-librespot[15036]: time="2024-08-27T00:32:01+02:00" level=info msg="generated new device id: a416ec56d0a94c97997245b809375246a08e9731" Aug 27 00:32:01 lms-sdb go-librespot[15036]: time="2024-08-27T00:32:01+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:32:01 lms-sdb go-librespot[15036]: time="2024-08-27T00:32:01+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:32:01 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:32:01 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:32:02 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="IOT_MUSICNOTIF" Aug 27 00:32:02 lms-sdb wpa_supplicant[1129]: wlan0: Failed to initiate sched scan Aug 27 00:32:02 lms-sdb volumio[15013]: info: MYVOLUMIO Environment detected Aug 27 00:32:02 lms-sdb volumio[15013]: info: Plugin folders cleanup Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning into folder /volumio/app/plugins/ Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category audio_interface Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category miscellanea Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category music_service Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category plugins.json Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category system_controller Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category user_interface Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning into folder /data/plugins/ Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category audio_interface Aug 27 00:32:02 lms-sdb volumio[15013]: info: Scanning category music_service Aug 27 00:32:02 lms-sdb volumio[15013]: info: Plugin folders cleanup completed Aug 27 00:32:02 lms-sdb volumio[15013]: info: ------------------------------------------- Aug 27 00:32:02 lms-sdb volumio[15013]: info: ----- Core plugins startup ---- Aug 27 00:32:02 lms-sdb volumio[15013]: info: ------------------------------------------- Aug 27 00:32:02 lms-sdb volumio[15013]: info: Loading plugins from folder /volumio/app/plugins/ Aug 27 00:32:02 lms-sdb volumio[15013]: info: Adding plugin upnp to MyMusic Plugins Aug 27 00:32:02 lms-sdb volumio[15013]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 27 00:32:02 lms-sdb volumio[15013]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 27 00:32:02 lms-sdb volumio[15013]: info: Loading plugins from folder /data/plugins/ Aug 27 00:32:02 lms-sdb volumio[15013]: info: Loading plugin "system"... Aug 27 00:32:02 lms-sdb volumio[15013]: info: Loading plugin "appearance"... Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "network"... Aug 27 00:32:03 lms-sdb volumio[15013]: info: Refreshing Cached IP Addresses Aug 27 00:32:03 lms-sdb sudo[15050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 00:32:03 lms-sdb sudo[15050]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:03 lms-sdb sudo[15050]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:03 lms-sdb sudo[15052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 00:32:03 lms-sdb sudo[15052]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "services"... Aug 27 00:32:03 lms-sdb sudo[15052]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "alsa_controller"... Aug 27 00:32:03 lms-sdb sudo[15055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 27 00:32:03 lms-sdb sudo[15055]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:03 lms-sdb sudo[15055]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:03 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "wizard"... Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "networkfs"... Aug 27 00:32:03 lms-sdb volumio[15013]: info: Starting Udev Watcher for removable devices Aug 27 00:32:03 lms-sdb volumio[15013]: info: Ignoring mount for partition: boot Aug 27 00:32:03 lms-sdb volumio[15013]: info: Ignoring mount for partition: volumio Aug 27 00:32:03 lms-sdb volumio[15013]: info: Ignoring mount for partition: volumio_data Aug 27 00:32:03 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "volumio_command_line_client"... Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "upnp"... Aug 27 00:32:03 lms-sdb volumio[15013]: info: [1724711523852] Starting Upmpd Daemon Aug 27 00:32:03 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "my_music"... Aug 27 00:32:03 lms-sdb volumio[15013]: info: Loading plugin "mpd"... Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "upnp_browser"... Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "alarm-clock"... Aug 27 00:32:04 lms-sdb wpa_supplicant[1129]: wlan0: Trying to associate with SSID 'IOT_MUSICNOTIF' Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "airplay_emulation"... Aug 27 00:32:04 lms-sdb volumio[15013]: info: Starting Shairport Sync Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "last_100"... Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "webradio"... Aug 27 00:32:04 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:32:04 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 27 00:32:04 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "i2s_dacs"... Aug 27 00:32:04 lms-sdb volumio[15013]: info: I2S DAC not set, start Auto-detection Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "volumiodiscovery"... Aug 27 00:32:04 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:32:04 lms-sdb go-librespot[15062]: Librespot-go daemon starting... Aug 27 00:32:04 lms-sdb go-librespot[15062]: time="2024-08-27T00:32:04+02:00" level=info msg="generated new device id: 6c60575fce42e4a6635049608441b2b690fa8ba8" Aug 27 00:32:04 lms-sdb go-librespot[15062]: time="2024-08-27T00:32:04+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:32:04 lms-sdb volumio[15013]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:32:04 lms-sdb volumio[15013]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:32:04 lms-sdb volumio[15013]: *** WARNING *** For more information see Aug 27 00:32:04 lms-sdb node[15013]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 27 00:32:04 lms-sdb volumio[15013]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:32:04 lms-sdb volumio[15013]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:32:04 lms-sdb volumio[15013]: *** WARNING *** For more information see Aug 27 00:32:04 lms-sdb node[15013]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:32:04 lms-sdb node[15013]: *** WARNING *** For more information see Aug 27 00:32:04 lms-sdb node[15013]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 27 00:32:04 lms-sdb node[15013]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 27 00:32:04 lms-sdb node[15013]: *** WARNING *** For more information see Aug 27 00:32:04 lms-sdb volumio[15013]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 27 00:32:04 lms-sdb go-librespot[15062]: time="2024-08-27T00:32:04+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:32:04 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:32:04 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:32:04 lms-sdb volumio[15013]: info: Discovery: Started advertising with name: LMS-SDB Aug 27 00:32:04 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 27 00:32:04 lms-sdb volumio[15013]: info: Loading plugin "spop"... Aug 27 00:32:06 lms-sdb volumio-remote-updater[622]: [2024-08-27 00:32:06] [connect] Successful connection Aug 27 00:32:06 lms-sdb volumio[15013]: info: Loading plugin "squeezelite_mc"... Aug 27 00:32:06 lms-sdb volumio[15013]: info: Loading plugin "outputs"... Aug 27 00:32:06 lms-sdb volumio[15013]: info: Loading plugin "albumart"... Aug 27 00:32:07 lms-sdb volumio[15013]: info: Plugin example_plugin is not enabled Aug 27 00:32:07 lms-sdb volumio[15013]: info: Loading plugin "inputs"... Aug 27 00:32:07 lms-sdb volumio[15013]: info: Loading plugin "updater_comm"... Aug 27 00:32:07 lms-sdb volumio[15013]: info: Plugin mpdemulation is not enabled Aug 27 00:32:07 lms-sdb volumio[15013]: info: Loading plugin "rest_api"... Aug 27 00:32:07 lms-sdb volumio[15013]: info: Loading plugin "websocket"... Aug 27 00:32:07 lms-sdb volumio[15013]: info: Starting Socket.io Server version 2.3.0 Aug 27 00:32:07 lms-sdb volumio[15013]: info: Plugin fusiondsp is not enabled Aug 27 00:32:07 lms-sdb volumio[15013]: info: Loading i18n strings for locale fr Aug 27 00:32:07 lms-sdb volumio[15013]: Updating browse sources language Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:32:07 lms-sdb dhcpcd[1141]: wlan0: carrier acquired Aug 27 00:32:07 lms-sdb wpa_supplicant[1129]: wlan0: Associated with fa:92:bf:61:ad:85 Aug 27 00:32:07 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-CONNECTED - Connection to fa:92:bf:61:ad:85 completed [id=0 id_str=] Aug 27 00:32:07 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 27 00:32:07 lms-sdb wpa_supplicant[1129]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=FR Aug 27 00:32:07 lms-sdb dhcpcd[1141]: wlan0: IAID eb:d4:64:7e Aug 27 00:32:07 lms-sdb dhcpcd[1141]: wlan0: carrier lost Aug 27 00:32:07 lms-sdb dhcpcd[1141]: wlan0: carrier acquired Aug 27 00:32:07 lms-sdb dhcpcd[1141]: wlan0: IAID eb:d4:64:7e Aug 27 00:32:07 lms-sdb dhcpcd[1141]: wlan0: soliciting an IPv6 router Aug 27 00:32:07 lms-sdb volumio[15013]: Forking 3 albumart workers Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::initPlayerControls Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: Express server listening on port 3000 Aug 27 00:32:07 lms-sdb volumio[15013]: [Metrics] WebUI: 6s 624.68ms Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreStateMachine::resetVolumioState Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreStateMachine::getcurrentVolume Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:32:07 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:32:07 lms-sdb volumio[15013]: info: Cannot read play queue from file Aug 27 00:32:07 lms-sdb volumio[15013]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 27 00:32:07 lms-sdb volumio[15013]: wlan0 Interface doesn't support scanning : Device or resource busy Aug 27 00:32:07 lms-sdb volumio[15013]: info: Cannot use regular scanning, forcing with ap-force Aug 27 00:32:07 lms-sdb sudo[15117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 27 00:32:07 lms-sdb sudo[15117]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:08 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:32:08 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 27 00:32:08 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:32:08 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:32:08 lms-sdb go-librespot[15119]: Librespot-go daemon starting... Aug 27 00:32:08 lms-sdb go-librespot[15119]: time="2024-08-27T00:32:08+02:00" level=info msg="generated new device id: 7fc3b8866a159da83571e1c2dee1219fc283e7a9" Aug 27 00:32:08 lms-sdb go-librespot[15119]: time="2024-08-27T00:32:08+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:32:08 lms-sdb go-librespot[15119]: time="2024-08-27T00:32:08+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:32:08 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:32:08 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:32:08 lms-sdb dhcpcd[1141]: wlan0: rebinding lease of 192.168.30.15 Aug 27 00:32:08 lms-sdb volumio[15013]: Starting albumart workers Aug 27 00:32:08 lms-sdb dhcpcd[1141]: wlan0: probing address 192.168.30.15/24 Aug 27 00:32:08 lms-sdb volumio[15013]: Starting albumart workers Aug 27 00:32:08 lms-sdb volumio[15013]: Starting albumart workers Aug 27 00:32:11 lms-sdb systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 27 00:32:11 lms-sdb systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 27 00:32:11 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:32:11 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:32:11 lms-sdb go-librespot[15150]: Librespot-go daemon starting... Aug 27 00:32:11 lms-sdb go-librespot[15150]: time="2024-08-27T00:32:11+02:00" level=info msg="generated new device id: 3e1cd5a6a8a2c3f2966be19b42b3cf0f146ccd2e" Aug 27 00:32:11 lms-sdb go-librespot[15150]: time="2024-08-27T00:32:11+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:32:11 lms-sdb go-librespot[15150]: time="2024-08-27T00:32:11+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:32:11 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:32:11 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:32:11 lms-sdb sudo[15117]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreStateMachine::setRepeat null single undefined Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreStateMachine::pushState Aug 27 00:32:11 lms-sdb volumio[15013]: info: CorePlayQueue::getTrack 0 Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioPushState Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreStateMachine::setRandom null Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreStateMachine::pushState Aug 27 00:32:11 lms-sdb volumio[15013]: info: CorePlayQueue::getTrack 0 Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioPushState Aug 27 00:32:11 lms-sdb volumio[15013]: info: Setting Device type: Raspberry PI Aug 27 00:32:11 lms-sdb volumio[15013]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreStateMachine::pushState Aug 27 00:32:11 lms-sdb volumio[15013]: info: CorePlayQueue::getTrack 0 Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioPushState Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreStateMachine::updateTrackBlock Aug 27 00:32:11 lms-sdb volumio[15013]: info: CorePlayQueue::getTrackBlock Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:32:11 lms-sdb volumio[15013]: info: Completed loading Core Plugins Aug 27 00:32:11 lms-sdb volumio[15013]: info: Preparing to generate the ALSA configuration file Aug 27 00:32:11 lms-sdb volumio[15013]: info: Asound.conf file unchanged, so no further update is needed Aug 27 00:32:11 lms-sdb volumio[15013]: info: Output device has changed, restarting MPD Aug 27 00:32:11 lms-sdb sudo[15165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:32:11 lms-sdb sudo[15165]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:11 lms-sdb volumio[15013]: info: Output device has changed, restarting Shairport Sync Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:11 lms-sdb sudo[15165]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:32:11 lms-sdb sudo[15168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:32:11 lms-sdb sudo[15168]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:11 lms-sdb systemd[1]: Stopping Music Player Daemon... Aug 27 00:32:11 lms-sdb volumio[15013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:32:11 lms-sdb volumio[15013]: info: ___________ START PLUGINS ___________ Aug 27 00:32:11 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:32:11 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:32:11 lms-sdb volumio[15013]: info: ControllerMpd::onStart: Initializing MPD Aug 27 00:32:11 lms-sdb volumio[15013]: info: Creating MPD Configuration file Aug 27 00:32:11 lms-sdb sudo[15175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 27 00:32:11 lms-sdb sudo[15175]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:32:11 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:32:11 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:32:11 lms-sdb volumio[15013]: info: [1724711531995] CoreMusicLibrary::Adding element Serveurs Média Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:32:12 lms-sdb sudo[15175]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:12 lms-sdb sudo[15178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 27 00:32:12 lms-sdb sudo[15178]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:32:12 lms-sdb systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 27 00:32:12 lms-sdb systemd[1]: mpd.service: Succeeded. Aug 27 00:32:12 lms-sdb systemd[1]: Stopped Music Player Daemon. Aug 27 00:32:12 lms-sdb systemd[1]: Starting Music Player Daemon... Aug 27 00:32:12 lms-sdb volumio[15013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:32:12 lms-sdb volumio[15013]: info: [1724711532140] CoreMusicLibrary::Adding element Last_100 Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 00:32:12 lms-sdb volumio[15013]: info: [1724711532143] CoreMusicLibrary::Adding element Webradio Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:32:12 lms-sdb volumio[15013]: info: Initializing BBC Radios Aug 27 00:32:12 lms-sdb sudo[15184]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 27 00:32:12 lms-sdb sudo[15184]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:12 lms-sdb sudo[15184]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: Creating Spotify config file Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: [squeezelite_mc] Starting proxy server... Aug 27 00:32:12 lms-sdb volumio[15013]: info: Volumio Calling Home Aug 27 00:32:12 lms-sdb volumio[15013]: info: [squeezelite_mc] Proxy server started on port 38117 Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioRetrievevolume Aug 27 00:32:12 lms-sdb volumio[15013]: Unhandled rejection Error: No sockets available, cannot start. Aug 27 00:32:12 lms-sdb volumio[15013]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Aug 27 00:32:12 lms-sdb volumio[15013]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Aug 27 00:32:12 lms-sdb volumio[15013]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Aug 27 00:32:12 lms-sdb volumio[15013]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Aug 27 00:32:12 lms-sdb volumio[15013]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Aug 27 00:32:12 lms-sdb volumio[15013]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Aug 27 00:32:12 lms-sdb volumio[15013]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Aug 27 00:32:12 lms-sdb volumio[15013]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Aug 27 00:32:12 lms-sdb volumio[15013]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Aug 27 00:32:12 lms-sdb volumio[15013]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Aug 27 00:32:12 lms-sdb volumio[15013]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Aug 27 00:32:12 lms-sdb volumio[15013]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Aug 27 00:32:12 lms-sdb volumio[15013]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Aug 27 00:32:12 lms-sdb volumio[15013]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Aug 27 00:32:12 lms-sdb volumio[15013]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Aug 27 00:32:12 lms-sdb volumio[15013]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 27 00:32:12 lms-sdb volumio[15013]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Aug 27 00:32:12 lms-sdb volumio[15013]: info: MPD Permissions set Aug 27 00:32:12 lms-sdb volumio[15013]: info: MPD Permissions set Aug 27 00:32:12 lms-sdb volumio[15013]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreStateMachine::pushState Aug 27 00:32:12 lms-sdb volumio[15013]: info: CorePlayQueue::getTrack 0 Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioPushState Aug 27 00:32:12 lms-sdb volumio[15013]: info: Spotify config file written Aug 27 00:32:12 lms-sdb sudo[15207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 00:32:12 lms-sdb sudo[15207]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:12 lms-sdb volumio[15013]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb systemd[1]: Stopped go-librespot Daemon. Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb systemd[1]: Started go-librespot Daemon. Aug 27 00:32:12 lms-sdb go-librespot[15210]: Librespot-go daemon starting... Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb sudo[15207]: pam_unix(sudo:session): session closed for user root Aug 27 00:32:12 lms-sdb go-librespot[15210]: time="2024-08-27T00:32:12+02:00" level=info msg="generated new device id: 8c9a2423bc5657d4fcfa682d42599fdd708ca213" Aug 27 00:32:12 lms-sdb go-librespot[15210]: time="2024-08-27T00:32:12+02:00" level=debug msg="stored credentials found for 1144140704" Aug 27 00:32:12 lms-sdb go-librespot[15210]: time="2024-08-27T00:32:12+02: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: lookup clienttoken.spotify.com: device or resource busy" Aug 27 00:32:12 lms-sdb systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 00:32:12 lms-sdb systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 00:32:12 lms-sdb volumio[15013]: info: VolumeController:: Volume=83 Mute =false Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreStateMachine::pushState Aug 27 00:32:12 lms-sdb volumio[15013]: info: CorePlayQueue::getTrack 0 Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::volumioPushState Aug 27 00:32:12 lms-sdb volumio[15013]: info: [squeezelite_mc] Server discovery started Aug 27 00:32:12 lms-sdb volumio[15013]: info: [squeezelite_mc] Player finder started Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 00:32:12 lms-sdb volumio[15013]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 27 00:32:12 lms-sdb volumio[15013]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:32:12 lms-sdb volumio[15013]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 27 00:32:12 lms-sdb volumio[15013]: at doSend (dgram.js:692:16) Aug 27 00:32:12 lms-sdb volumio[15013]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 27 00:32:12 lms-sdb volumio[15013]: at afterDns (dgram.js:638:5) Aug 27 00:32:12 lms-sdb volumio[15013]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 27 00:32:12 lms-sdb volumio[15013]: errno: -101, Aug 27 00:32:12 lms-sdb volumio[15013]: code: 'ENETUNREACH', Aug 27 00:32:12 lms-sdb volumio[15013]: syscall: 'send', Aug 27 00:32:12 lms-sdb volumio[15013]: address: '255.255.255.255', Aug 27 00:32:12 lms-sdb volumio[15013]: port: 3483 Aug 27 00:32:12 lms-sdb volumio[15013]: } Aug 27 00:32:12 lms-sdb volumio[15013]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 00:32:13 lms-sdb sudo[15235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 00:31 Aug 27 00:32:13 lms-sdb sudo[15235]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 27 00:32:13 lms-sdb dhcpcd[1141]: wlan0: leased 192.168.30.15 for 86400 seconds Aug 27 00:32:13 lms-sdb avahi-daemon[648]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.30.15. Aug 27 00:32:13 lms-sdb dhcpcd[1141]: wlan0: adding route to 192.168.30.0/24 Aug 27 00:32:13 lms-sdb dhcpcd[1141]: wlan0: adding default route via 192.168.30.1 Aug 27 00:32:13 lms-sdb avahi-daemon[648]: New relevant interface wlan0.IPv4 for mDNS. Aug 27 00:32:13 lms-sdb avahi-daemon[648]: Registering new address record for 192.168.30.15 on wlan0.IPv4. 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"