-- Logs begin at Sun 2024-09-08 17:21:02 CEST, end at Mon 2024-09-09 05:01:57 CEST. -- Sep 09 05:00:10 volumio dhcpcd[1208]: eth0: carrier lost Sep 09 05:00:10 volumio dhcpcd[1162]: eth0: carrier lost Sep 09 05:00:10 volumio kernel: macb 1f00100000.ethernet eth0: Link is Down Sep 09 05:00:10 volumio dhcpcd[1162]: eth0: deleting route to 192.168.1.0/24 Sep 09 05:00:10 volumio dhcpcd[1162]: eth0: deleting default route via 192.168.1.254 Sep 09 05:00:10 volumio avahi-daemon[833]: Withdrawing address record for 192.168.1.129 on eth0. Sep 09 05:00:10 volumio avahi-daemon[833]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.129. Sep 09 05:00:10 volumio avahi-daemon[833]: Interface eth0.IPv4 no longer relevant for mDNS. Sep 09 05:00:10 volumio volumio[1269]: info: Discovery: A device disappeared from network Sep 09 05:00:10 volumio dhcpcd[1208]: eth0: deleting route to 192.168.1.0/24 Sep 09 05:00:10 volumio dhcpcd[1208]: eth0: deleting default route via 192.168.1.254 Sep 09 05:00:10 volumio volumio[1269]: info: Discovery: A device disappeared from network Sep 09 05:00:10 volumio volumio[1269]: info: Discovery: Device volumio disappeared from network Sep 09 05:00:10 volumio volumio[1269]: info: Discovery: Disconnected from remote: 192.168.1.64 Sep 09 05:00:10 volumio volumio[1269]: info: Discovery: Device volumio disappeared from network Sep 09 05:00:10 volumio nmbd[955]: [2024/09/09 05:00:10.495106, 0] ../source3/libsmb/nmblib.c:917(send_udp) Sep 09 05:00:10 volumio nmbd[955]: Packet send failed to 192.168.1.255(138) ERRNO=Network is unreachable Sep 09 05:00:10 volumio ifplugd(eth0)[1000]: Link beat lost. Sep 09 05:00:11 volumio ntpd[986]: Deleting interface #3 eth0, 192.168.1.129#123, interface stats: received=946, sent=950, dropped=0, active_time=41936 secs Sep 09 05:00:11 volumio ntpd[986]: 94.198.159.15 local addr 192.168.1.129 -> Sep 09 05:00:11 volumio ntpd[986]: 45.138.55.61 local addr 192.168.1.129 -> Sep 09 05:00:11 volumio ntpd[986]: 81.172.225.142 local addr 192.168.1.129 -> Sep 09 05:00:11 volumio ntpd[986]: 178.239.19.60 local addr 192.168.1.129 -> Sep 09 05:00:11 volumio ntpd[986]: 178.239.19.59 local addr 192.168.1.129 -> Sep 09 05:00:11 volumio ntpd[986]: 206.189.110.141 local addr 192.168.1.129 -> Sep 09 05:00:11 volumio ntpd[986]: 185.224.145.68 local addr 192.168.1.129 -> Sep 09 05:00:20 volumio ifplugd(eth0)[1000]: Executing '/etc/ifplugd/ifplugd.action eth0 down'. Sep 09 05:00:20 volumio ifplugd(eth0)[1000]: client: sending commands to master dhcpcd process Sep 09 05:00:20 volumio dhcpcd[32461]: sending commands to master dhcpcd process Sep 09 05:00:20 volumio dhcpcd[1208]: control command: /sbin/dhcpcd -k eth0 Sep 09 05:00:20 volumio dhcpcd[1208]: eth0: removing interface Sep 09 05:00:20 volumio kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock unregistered. Sep 09 05:00:20 volumio ifplugd(eth0)[1000]: Program executed successfully. Sep 09 05:00:20 volumio kernel: macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL) Sep 09 05:00:20 volumio kernel: macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode Sep 09 05:00:20 volumio kernel: pps pps0: new PPS source ptp0 Sep 09 05:00:20 volumio kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered. Sep 09 05:00:24 volumio dhcpcd[1162]: eth0: carrier acquired Sep 09 05:00:24 volumio kernel: macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Sep 09 05:00:24 volumio dhcpcd[1162]: eth0: IAID 67:4a:c6:65 Sep 09 05:00:24 volumio dhcpcd[1162]: eth0: soliciting an IPv6 router Sep 09 05:00:24 volumio dhcpcd[1162]: eth0: rebinding lease of 192.168.1.129 Sep 09 05:00:24 volumio ifplugd(eth0)[1000]: Link beat detected. Sep 09 05:00:25 volumio ifplugd(eth0)[1000]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Sep 09 05:00:25 volumio dhcpcd[32517]: sending commands to master dhcpcd process Sep 09 05:00:25 volumio ifplugd(eth0)[1000]: client: sending commands to master dhcpcd process Sep 09 05:00:25 volumio dhcpcd[1208]: control command: /sbin/dhcpcd eth0 Sep 09 05:00:25 volumio dhcpcd[1208]: eth0: carrier acquired Sep 09 05:00:25 volumio dhcpcd[1208]: eth0: IAID 67:4a:c6:65 Sep 09 05:00:25 volumio dhcpcd[1208]: eth0: rebinding lease of 192.168.1.129 Sep 09 05:00:25 volumio ifplugd(eth0)[1000]: Program executed successfully. Sep 09 05:00:25 volumio dhcpcd[1208]: eth0: soliciting an IPv6 router Sep 09 05:00:27 volumio dhcpcd[1208]: eth0: carrier lost Sep 09 05:00:27 volumio dhcpcd[1162]: eth0: carrier lost Sep 09 05:00:27 volumio kernel: macb 1f00100000.ethernet eth0: Link is Down Sep 09 05:00:27 volumio ifplugd(eth0)[1000]: Link beat lost. Sep 09 05:00:28 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-DISCONNECTED bssid=d2:7c:3f:b6:d6:6c reason=0 locally_generated=1 Sep 09 05:00:28 volumio dhcpcd[1208]: wlan0: carrier lost Sep 09 05:00:28 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Sep 09 05:00:28 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=DE Sep 09 05:00:28 volumio avahi-daemon[833]: Withdrawing address record for 192.168.1.130 on wlan0. Sep 09 05:00:28 volumio avahi-daemon[833]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.130. Sep 09 05:00:28 volumio avahi-daemon[833]: Interface wlan0.IPv4 no longer relevant for mDNS. Sep 09 05:00:28 volumio dhcpcd[1208]: wlan0: deleting route to 192.168.1.0/24 Sep 09 05:00:28 volumio dhcpcd[1208]: wlan0: deleting default route via 192.168.1.254 Sep 09 05:00:28 volumio volumio[1269]: info: Discovery: A device disappeared from network Sep 09 05:00:28 volumio volumio[1269]: info: Discovery: A device disappeared from network Sep 09 05:00:29 volumio ntpd[986]: Deleting interface #8 wlan0, 192.168.1.130#123, interface stats: received=1, sent=12, dropped=0, active_time=15388 secs Sep 09 05:00:29 volumio ntpd[986]: 185.224.145.68 local addr 192.168.1.130 -> Sep 09 05:00:29 volumio ntpd[986]: 206.189.110.141 local addr 192.168.1.130 -> Sep 09 05:00:29 volumio ntpd[986]: 178.239.19.59 local addr 192.168.1.130 -> Sep 09 05:00:29 volumio ntpd[986]: 178.239.19.60 local addr 192.168.1.130 -> Sep 09 05:00:29 volumio ntpd[986]: 81.172.225.142 local addr 192.168.1.130 -> Sep 09 05:00:29 volumio ntpd[986]: 45.138.55.61 local addr 192.168.1.130 -> Sep 09 05:00:29 volumio ntpd[986]: 94.198.159.15 local addr 192.168.1.130 -> Sep 09 05:00:30 volumio ntpd[986]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 09 05:00:30 volumio wpa_supplicant[1095]: wlan0: Trying to associate with SSID 'Sist' Sep 09 05:00:31 volumio ntpd[986]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 09 05:00:33 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Sep 09 05:00:35 volumio wpa_supplicant[1095]: wlan0: Trying to associate with SSID 'Sist' Sep 09 05:00:37 volumio ifplugd(eth0)[1000]: Executing '/etc/ifplugd/ifplugd.action eth0 down'. Sep 09 05:00:37 volumio ifplugd(eth0)[1000]: client: sending commands to master dhcpcd process Sep 09 05:00:37 volumio dhcpcd[32658]: sending commands to master dhcpcd process Sep 09 05:00:37 volumio dhcpcd[1208]: control command: /sbin/dhcpcd -k eth0 Sep 09 05:00:37 volumio dhcpcd[1208]: eth0: removing interface Sep 09 05:00:37 volumio kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock unregistered. Sep 09 05:00:37 volumio ifplugd(eth0)[1000]: Program executed successfully. Sep 09 05:00:37 volumio kernel: macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL) Sep 09 05:00:37 volumio kernel: macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode Sep 09 05:00:37 volumio kernel: pps pps0: new PPS source ptp0 Sep 09 05:00:37 volumio kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered. Sep 09 05:00:37 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Sep 09 05:00:40 volumio wpa_supplicant[1095]: wlan0: Trying to associate with SSID 'Sist' Sep 09 05:00:42 volumio dhcpcd[1162]: eth0: carrier acquired Sep 09 05:00:42 volumio kernel: macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Sep 09 05:00:42 volumio dhcpcd[1162]: eth0: IAID 67:4a:c6:65 Sep 09 05:00:42 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Sep 09 05:00:43 volumio dhcpcd[1162]: eth0: rebinding lease of 192.168.1.129 Sep 09 05:00:43 volumio dhcpcd[1162]: eth0: soliciting an IPv6 router Sep 09 05:00:43 volumio ifplugd(eth0)[1000]: Link beat detected. Sep 09 05:00:43 volumio ifplugd(eth0)[1000]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Sep 09 05:00:43 volumio dhcpcd[32744]: sending commands to master dhcpcd process Sep 09 05:00:43 volumio dhcpcd[1208]: control command: /sbin/dhcpcd eth0 Sep 09 05:00:43 volumio ifplugd(eth0)[1000]: client: sending commands to master dhcpcd process Sep 09 05:00:43 volumio dhcpcd[1208]: eth0: carrier acquired Sep 09 05:00:43 volumio dhcpcd[1208]: eth0: IAID 67:4a:c6:65 Sep 09 05:00:43 volumio ifplugd(eth0)[1000]: Program executed successfully. Sep 09 05:00:43 volumio dhcpcd[1208]: eth0: rebinding lease of 192.168.1.129 Sep 09 05:00:43 volumio dhcpcd[1208]: eth0: soliciting an IPv6 router Sep 09 05:00:44 volumio volumio[1269]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:00:44 volumio volumio[1269]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 09 05:00:44 volumio volumio[1269]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 09 05:00:44 volumio volumio[1269]: errno: -16, Sep 09 05:00:44 volumio volumio[1269]: code: 'EBUSY', Sep 09 05:00:44 volumio volumio[1269]: syscall: 'getaddrinfo', Sep 09 05:00:44 volumio volumio[1269]: hostname: 'ws.audioscrobbler.com' Sep 09 05:00:44 volumio volumio[1269]: } Sep 09 05:00:44 volumio volumio[1269]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:00:44 volumio sudo[314]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-09 04:59 Sep 09 05:00:44 volumio sudo[314]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:44 volumio sudo[314]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:44 volumio volumio-remote-updater[840]: [2024-09-09 05:00:44] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 09 05:00:44 volumio volumio-remote-updater[840]: [2024-09-09 05:00:44] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 09 05:00:44 volumio go-librespot[1463]: time="2024-09-09T05:00:44+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Sep 09 05:00:44 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 09 05:00:44 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 09 05:00:45 volumio systemd[1]: Started dynamicswap service. Sep 09 05:00:45 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 09 05:00:45 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 09 05:00:45 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Sep 09 05:00:45 volumio systemd[1]: Started dynamicswap service. Sep 09 05:00:45 volumio systemd[1]: Stopped Volumio Backend Module. Sep 09 05:00:45 volumio systemd[1]: Started Volumio Backend Module. Sep 09 05:00:45 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 09 05:00:45 volumio volumio[330]: info: ------------------------------------------- Sep 09 05:00:45 volumio volumio[330]: info: ----- Volumio3 ---- Sep 09 05:00:45 volumio volumio[330]: info: ------------------------------------------- Sep 09 05:00:45 volumio volumio[330]: info: ----- System startup ---- Sep 09 05:00:45 volumio volumio[330]: info: ------------------------------------------- Sep 09 05:00:45 volumio volumio[330]: info: MYVOLUMIO Environment detected Sep 09 05:00:45 volumio volumio[330]: info: Plugin folders cleanup Sep 09 05:00:45 volumio volumio[330]: info: Scanning into folder /volumio/app/plugins/ Sep 09 05:00:45 volumio volumio[330]: info: Scanning category audio_interface Sep 09 05:00:45 volumio volumio[330]: info: Scanning category miscellanea Sep 09 05:00:45 volumio volumio[330]: info: Scanning category music_service Sep 09 05:00:45 volumio volumio[330]: info: Scanning category plugins.json Sep 09 05:00:45 volumio volumio[330]: info: Scanning category system_controller Sep 09 05:00:45 volumio volumio[330]: info: Scanning category user_interface Sep 09 05:00:45 volumio volumio[330]: info: Scanning into folder /data/plugins/ Sep 09 05:00:45 volumio volumio[330]: info: Scanning category music_service Sep 09 05:00:45 volumio volumio[330]: info: Scanning category system_controller Sep 09 05:00:45 volumio volumio[330]: info: Scanning category user_interface Sep 09 05:00:45 volumio volumio[330]: info: Plugin folders cleanup completed Sep 09 05:00:45 volumio volumio[330]: info: ------------------------------------------- Sep 09 05:00:45 volumio volumio[330]: info: ----- Core plugins startup ---- Sep 09 05:00:45 volumio volumio[330]: info: ------------------------------------------- Sep 09 05:00:45 volumio volumio[330]: info: Loading plugins from folder /volumio/app/plugins/ Sep 09 05:00:45 volumio volumio[330]: info: Adding plugin upnp to MyMusic Plugins Sep 09 05:00:45 volumio volumio[330]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 09 05:00:45 volumio volumio[330]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 09 05:00:45 volumio volumio[330]: info: Loading plugins from folder /data/plugins/ Sep 09 05:00:45 volumio volumio[330]: info: Loading plugin "system"... Sep 09 05:00:45 volumio volumio[330]: info: Loading plugin "appearance"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "network"... Sep 09 05:00:46 volumio volumio[330]: info: Refreshing Cached IP Addresses Sep 09 05:00:46 volumio sudo[358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 09 05:00:46 volumio sudo[358]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:46 volumio sudo[358]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:46 volumio sudo[360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 09 05:00:46 volumio sudo[360]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "services"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "alsa_controller"... Sep 09 05:00:46 volumio sudo[360]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:46 volumio sudo[363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 09 05:00:46 volumio sudo[363]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:46 volumio sudo[363]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "wizard"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "networkfs"... Sep 09 05:00:46 volumio volumio[330]: info: Cannot mount NAS Muziek at system boot, trial number 1 ,retrying in 5 seconds Sep 09 05:00:46 volumio volumio[330]: info: Starting Udev Watcher for removable devices Sep 09 05:00:46 volumio sudo[369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.115/muziek /mnt/NAS/muziek Sep 09 05:00:46 volumio sudo[369]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:46 volumio sudo[369]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:46 volumio volumio[330]: info: Ignoring mount for partition: boot Sep 09 05:00:46 volumio volumio[330]: info: Ignoring mount for partition: volumio Sep 09 05:00:46 volumio volumio[330]: info: Ignoring mount for partition: volumio_data Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "volumio_command_line_client"... Sep 09 05:00:46 volumio kernel: CIFS: Attempting to mount \\192.168.1.115\muziek Sep 09 05:00:46 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Sep 09 05:00:46 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "upnp"... Sep 09 05:00:46 volumio volumio[330]: info: [1725850846139] Starting Upmpd Daemon Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "my_music"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "mpd"... Sep 09 05:00:46 volumio wpa_supplicant[1095]: wlan0: Trying to associate with SSID 'Sist' Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "upnp_browser"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "alarm-clock"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "airplay_emulation"... Sep 09 05:00:46 volumio volumio[330]: info: Starting Shairport Sync Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "last_100"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "webradio"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "i2s_dacs"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "volumiodiscovery"... Sep 09 05:00:46 volumio volumio[330]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:46 volumio node[330]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:46 volumio node[330]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:46 volumio volumio[330]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:46 volumio volumio[330]: *** WARNING *** For more information see Sep 09 05:00:46 volumio volumio[330]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:46 volumio volumio[330]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:46 volumio volumio[330]: *** WARNING *** For more information see Sep 09 05:00:46 volumio node[330]: *** WARNING *** For more information see Sep 09 05:00:46 volumio node[330]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:46 volumio node[330]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:46 volumio node[330]: *** WARNING *** For more information see Sep 09 05:00:46 volumio volumio[330]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 09 05:00:46 volumio volumio[330]: info: Discovery: Started advertising with name: Volumio Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "spop"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "outputs"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "albumart"... Sep 09 05:00:46 volumio volumio[330]: info: Plugin example_plugin is not enabled Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "inputs"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "updater_comm"... Sep 09 05:00:46 volumio volumio[330]: info: Plugin mpdemulation is not enabled Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "rest_api"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "websocket"... Sep 09 05:00:46 volumio volumio[330]: info: Starting Socket.io Server version 2.3.0 Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "myb"... Sep 09 05:00:46 volumio volumio[330]: Forking 3 albumart workers Sep 09 05:00:46 volumio volumio[330]: info: Applying required configuration parameters for plugin myb Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "backup_restore"... Sep 09 05:00:46 volumio volumio[330]: info: Applying required configuration parameters for plugin backup_restore Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "Systeminfo"... Sep 09 05:00:46 volumio volumio[330]: info: Loading plugin "lastfm"... Sep 09 05:00:46 volumio volumio[330]: Starting albumart workers Sep 09 05:00:46 volumio volumio[330]: Starting albumart workers Sep 09 05:00:46 volumio volumio[330]: Starting albumart workers Sep 09 05:00:46 volumio volumio[330]: info: Plugin peppyspectrum is not enabled Sep 09 05:00:46 volumio volumio[330]: info: Loading i18n strings for locale nl Sep 09 05:00:46 volumio volumio[330]: Updating browse sources language Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::initPlayerControls Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:46 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:47 volumio volumio[330]: Express server listening on port 3000 Sep 09 05:00:47 volumio volumio[330]: [Metrics] WebUI: 1s 432.82ms Sep 09 05:00:47 volumio volumio[330]: info: CoreStateMachine::resetVolumioState Sep 09 05:00:47 volumio volumio[330]: info: CoreStateMachine::getcurrentVolume Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioRetrievevolume Sep 09 05:00:47 volumio volumio[330]: info: CoreStateMachine::pushState Sep 09 05:00:47 volumio volumio[330]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:47 volumio volumio[330]: info: Cannot mount NAS muziek at system boot, trial number 1 ,retrying in 5 seconds Sep 09 05:00:47 volumio volumio[330]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 09 05:00:47 volumio volumio[330]: wlan0 Interface doesn't support scanning : Device or resource busy Sep 09 05:00:47 volumio volumio[330]: info: Cannot use regular scanning, forcing with ap-force Sep 09 05:00:47 volumio sudo[420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 09 05:00:47 volumio sudo[420]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio sudo[420]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio volumio[330]: command failed: Resource temporarily unavailable (-11) Sep 09 05:00:47 volumio volumio[330]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 09 05:00:47 volumio volumio[330]: command failed: Resource temporarily unavailable (-11) Sep 09 05:00:47 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3) Sep 09 05:00:47 volumio volumio[330]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: Reloading queue from file Sep 09 05:00:47 volumio volumio[330]: info: CoreStateMachine::setRepeat false single undefined Sep 09 05:00:47 volumio volumio[330]: info: CoreStateMachine::pushState Sep 09 05:00:47 volumio volumio[330]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:47 volumio volumio[330]: info: CoreStateMachine::setRandom null Sep 09 05:00:47 volumio volumio[330]: info: CoreStateMachine::pushState Sep 09 05:00:47 volumio volumio[330]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:47 volumio volumio[330]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 09 05:00:47 volumio volumio[330]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04170 Sep 09 05:00:47 volumio volumio[330]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 09 05:00:47 volumio volumio[330]: info: Setting Device type: Raspberry PI Sep 09 05:00:47 volumio volumio[330]: info: Completed loading Core Plugins Sep 09 05:00:47 volumio volumio[330]: info: Preparing to generate the ALSA configuration file Sep 09 05:00:47 volumio volumio[330]: info: Asound.conf file written Sep 09 05:00:47 volumio sudo[445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Sep 09 05:00:47 volumio sudo[445]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio sudo[445]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio volumio[330]: info: Output device has changed, restarting MPD Sep 09 05:00:47 volumio sudo[450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 09 05:00:47 volumio sudo[450]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio volumio[330]: info: Output device has changed, restarting Shairport Sync Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:47 volumio sudo[450]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio sudo[452]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 09 05:00:47 volumio sudo[452]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio systemd[1]: Stopping Music Player Daemon... Sep 09 05:00:47 volumio volumio[330]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:47 volumio volumio[330]: info: ___________ START PLUGINS ___________ Sep 09 05:00:47 volumio volumio[330]: info: ControllerMpd::onStart: Initializing MPD Sep 09 05:00:47 volumio volumio[330]: info: Creating MPD Configuration file Sep 09 05:00:47 volumio systemd[1]: mpd.service: Succeeded. Sep 09 05:00:47 volumio systemd[1]: Stopped Music Player Daemon. Sep 09 05:00:47 volumio sudo[459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 09 05:00:47 volumio sudo[459]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio systemd[1]: Starting Music Player Daemon... Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:47 volumio volumio[330]: info: [1725850847222] CoreMusicLibrary::Adding element Media Servers Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:47 volumio sudo[459]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio sudo[464]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 09 05:00:47 volumio sudo[464]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio volumio[330]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:47 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 09 05:00:47 volumio systemd[1]: mpd.service: Succeeded. Sep 09 05:00:47 volumio systemd[1]: Stopped Music Player Daemon. Sep 09 05:00:47 volumio systemd[1]: Starting Music Player Daemon... Sep 09 05:00:47 volumio volumio[330]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:47 volumio volumio[330]: info: [1725850847265] CoreMusicLibrary::Adding element Last_100 Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:47 volumio volumio[330]: info: [1725850847266] CoreMusicLibrary::Adding element Webradio Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:47 volumio volumio[330]: info: Initializing BBC Radios Sep 09 05:00:47 volumio sudo[469]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 09 05:00:47 volumio sudo[469]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio sudo[469]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: Creating Spotify config file Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:47 volumio volumio[330]: info: [1725850847317] CoreMusicLibrary::Adding element LastFM Sep 09 05:00:47 volumio volumio[330]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:47 volumio volumio[330]: Cannot find translation for source LastFM Sep 09 05:00:47 volumio volumio[330]: info: [LastFM] scrobbler initiated! Sep 09 05:00:47 volumio volumio[330]: info: [LastFM] extended logging: false Sep 09 05:00:47 volumio volumio[330]: info: [LastFM] try scrobble stream/radio plays: true Sep 09 05:00:47 volumio volumio[330]: info: [LastFM] Left init routine Sep 09 05:00:47 volumio volumio[330]: info: [LastFM] Socket already connected: true Sep 09 05:00:47 volumio volumio[330]: info: Volumio Calling Home Sep 09 05:00:47 volumio volumio[330]: Unhandled rejection Error: No sockets available, cannot start. Sep 09 05:00:47 volumio volumio[330]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Sep 09 05:00:47 volumio volumio[330]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Sep 09 05:00:47 volumio volumio[330]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Sep 09 05:00:47 volumio volumio[330]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Sep 09 05:00:47 volumio volumio[330]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Sep 09 05:00:47 volumio volumio[330]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Sep 09 05:00:47 volumio volumio[330]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Sep 09 05:00:47 volumio volumio[330]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Sep 09 05:00:47 volumio volumio[330]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Sep 09 05:00:47 volumio volumio[330]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Sep 09 05:00:47 volumio volumio[330]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Sep 09 05:00:47 volumio volumio[330]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Sep 09 05:00:47 volumio volumio[330]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Sep 09 05:00:47 volumio volumio[330]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Sep 09 05:00:47 volumio volumio[330]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Sep 09 05:00:47 volumio volumio[330]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Sep 09 05:00:47 volumio volumio[330]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Sep 09 05:00:47 volumio volumio[330]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:00:47 volumio volumio[330]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 09 05:00:47 volumio volumio[330]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 09 05:00:47 volumio volumio[330]: errno: -16, Sep 09 05:00:47 volumio volumio[330]: code: 'EBUSY', Sep 09 05:00:47 volumio volumio[330]: syscall: 'getaddrinfo', Sep 09 05:00:47 volumio volumio[330]: hostname: 'ws.audioscrobbler.com' Sep 09 05:00:47 volumio volumio[330]: } Sep 09 05:00:47 volumio volumio[330]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:00:47 volumio sudo[498]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-09 04:59 Sep 09 05:00:47 volumio sudo[498]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:47 volumio sudo[498]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio mpd[476]: Sep 09 05:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 09 05:00:47 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 09 05:00:47 volumio sudo[452]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio sudo[464]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:47 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 09 05:00:47 volumio systemd[1]: Started dynamicswap service. Sep 09 05:00:47 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 09 05:00:47 volumio systemd[1]: Started Music Player Daemon. Sep 09 05:00:47 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 09 05:00:47 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Sep 09 05:00:47 volumio systemd[1]: Stopped Volumio Backend Module. Sep 09 05:00:47 volumio systemd[1]: Started Volumio Backend Module. Sep 09 05:00:47 volumio systemd[1]: Started dynamicswap service. Sep 09 05:00:47 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 09 05:00:48 volumio dhcpcd[1162]: eth0: probing for an IPv4LL address Sep 09 05:00:48 volumio dhcpcd[1162]: eth0: DHCP lease expired Sep 09 05:00:48 volumio dhcpcd[1162]: eth0: soliciting a DHCP lease Sep 09 05:00:48 volumio volumio[515]: info: ------------------------------------------- Sep 09 05:00:48 volumio volumio[515]: info: ----- Volumio3 ---- Sep 09 05:00:48 volumio volumio[515]: info: ------------------------------------------- Sep 09 05:00:48 volumio volumio[515]: info: ----- System startup ---- Sep 09 05:00:48 volumio volumio[515]: info: ------------------------------------------- Sep 09 05:00:48 volumio volumio[515]: info: MYVOLUMIO Environment detected Sep 09 05:00:48 volumio volumio[515]: info: Plugin folders cleanup Sep 09 05:00:48 volumio volumio[515]: info: Scanning into folder /volumio/app/plugins/ Sep 09 05:00:48 volumio volumio[515]: info: Scanning category audio_interface Sep 09 05:00:48 volumio volumio[515]: info: Scanning category miscellanea Sep 09 05:00:48 volumio volumio[515]: info: Scanning category music_service Sep 09 05:00:48 volumio volumio[515]: info: Scanning category plugins.json Sep 09 05:00:48 volumio volumio[515]: info: Scanning category system_controller Sep 09 05:00:48 volumio volumio[515]: info: Scanning category user_interface Sep 09 05:00:48 volumio volumio[515]: info: Scanning into folder /data/plugins/ Sep 09 05:00:48 volumio volumio[515]: info: Scanning category music_service Sep 09 05:00:48 volumio volumio[515]: info: Scanning category system_controller Sep 09 05:00:48 volumio volumio[515]: info: Scanning category user_interface Sep 09 05:00:48 volumio volumio[515]: info: Plugin folders cleanup completed Sep 09 05:00:48 volumio volumio[515]: info: ------------------------------------------- Sep 09 05:00:48 volumio volumio[515]: info: ----- Core plugins startup ---- Sep 09 05:00:48 volumio volumio[515]: info: ------------------------------------------- Sep 09 05:00:48 volumio volumio[515]: info: Loading plugins from folder /volumio/app/plugins/ Sep 09 05:00:48 volumio volumio[515]: info: Adding plugin upnp to MyMusic Plugins Sep 09 05:00:48 volumio volumio[515]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 09 05:00:48 volumio volumio[515]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 09 05:00:48 volumio volumio[515]: info: Loading plugins from folder /data/plugins/ Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "system"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "appearance"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "network"... Sep 09 05:00:48 volumio volumio[515]: info: Refreshing Cached IP Addresses Sep 09 05:00:48 volumio sudo[555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 09 05:00:48 volumio sudo[555]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:48 volumio sudo[555]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:48 volumio sudo[557]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 09 05:00:48 volumio sudo[557]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:48 volumio sudo[557]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "services"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "alsa_controller"... Sep 09 05:00:48 volumio sudo[561]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 09 05:00:48 volumio sudo[561]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:48 volumio sudo[561]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:48 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3) Sep 09 05:00:48 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "wizard"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "networkfs"... Sep 09 05:00:48 volumio volumio[515]: info: Cannot mount NAS Muziek at system boot, trial number 1 ,retrying in 5 seconds Sep 09 05:00:48 volumio volumio[515]: info: Starting Udev Watcher for removable devices Sep 09 05:00:48 volumio sudo[566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.115/muziek /mnt/NAS/muziek Sep 09 05:00:48 volumio sudo[566]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:48 volumio sudo[566]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:48 volumio volumio[515]: info: Ignoring mount for partition: boot Sep 09 05:00:48 volumio volumio[515]: info: Ignoring mount for partition: volumio Sep 09 05:00:48 volumio volumio[515]: info: Ignoring mount for partition: volumio_data Sep 09 05:00:48 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "volumio_command_line_client"... Sep 09 05:00:48 volumio kernel: CIFS: Attempting to mount \\192.168.1.115\muziek Sep 09 05:00:48 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Sep 09 05:00:48 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Sep 09 05:00:48 volumio dhcpcd[1208]: eth0: probing for an IPv4LL address Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "upnp"... Sep 09 05:00:48 volumio volumio[515]: info: [1725850848659] Starting Upmpd Daemon Sep 09 05:00:48 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "my_music"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "mpd"... Sep 09 05:00:48 volumio dhcpcd[1208]: eth0: DHCP lease expired Sep 09 05:00:48 volumio dhcpcd[1208]: eth0: soliciting a DHCP lease Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "upnp_browser"... Sep 09 05:00:48 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Sep 09 05:00:48 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Sist" auth_failures=1 duration=10 reason=CONN_FAILED Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "alarm-clock"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "airplay_emulation"... Sep 09 05:00:48 volumio volumio[515]: info: Starting Shairport Sync Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "last_100"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "webradio"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "i2s_dacs"... Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "volumiodiscovery"... Sep 09 05:00:48 volumio volumio[515]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:48 volumio node[515]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:48 volumio node[515]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:48 volumio volumio[515]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:48 volumio volumio[515]: *** WARNING *** For more information see Sep 09 05:00:48 volumio volumio[515]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:48 volumio volumio[515]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:48 volumio volumio[515]: *** WARNING *** For more information see Sep 09 05:00:48 volumio node[515]: *** WARNING *** For more information see Sep 09 05:00:48 volumio node[515]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:48 volumio node[515]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:48 volumio node[515]: *** WARNING *** For more information see Sep 09 05:00:48 volumio volumio[515]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 09 05:00:48 volumio volumio[515]: info: Discovery: Started advertising with name: Volumio Sep 09 05:00:48 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:48 volumio volumio[515]: info: Loading plugin "spop"... Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "outputs"... Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "albumart"... Sep 09 05:00:49 volumio volumio[515]: info: Plugin example_plugin is not enabled Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "inputs"... Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "updater_comm"... Sep 09 05:00:49 volumio volumio[515]: info: Plugin mpdemulation is not enabled Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "rest_api"... Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "websocket"... Sep 09 05:00:49 volumio volumio[515]: info: Starting Socket.io Server version 2.3.0 Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "myb"... Sep 09 05:00:49 volumio volumio[515]: Forking 3 albumart workers Sep 09 05:00:49 volumio volumio[515]: info: Applying required configuration parameters for plugin myb Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "backup_restore"... Sep 09 05:00:49 volumio volumio[515]: info: Applying required configuration parameters for plugin backup_restore Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "Systeminfo"... Sep 09 05:00:49 volumio volumio[515]: info: Loading plugin "lastfm"... Sep 09 05:00:49 volumio volumio[515]: Starting albumart workers Sep 09 05:00:49 volumio volumio[515]: Starting albumart workers Sep 09 05:00:49 volumio volumio[515]: Starting albumart workers Sep 09 05:00:49 volumio volumio[515]: info: Plugin peppyspectrum is not enabled Sep 09 05:00:49 volumio volumio[515]: info: Loading i18n strings for locale nl Sep 09 05:00:49 volumio volumio[515]: Updating browse sources language Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::initPlayerControls Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:49 volumio volumio[515]: Express server listening on port 3000 Sep 09 05:00:49 volumio volumio[515]: [Metrics] WebUI: 1s 474.08ms Sep 09 05:00:49 volumio volumio[515]: info: CoreStateMachine::resetVolumioState Sep 09 05:00:49 volumio volumio[515]: info: CoreStateMachine::getcurrentVolume Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::volumioRetrievevolume Sep 09 05:00:49 volumio volumio[515]: info: CoreStateMachine::pushState Sep 09 05:00:49 volumio volumio[515]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 09 05:00:49 volumio volumio[515]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:49 volumio volumio[515]: info: Cannot mount NAS muziek at system boot, trial number 1 ,retrying in 5 seconds Sep 09 05:00:49 volumio volumio[515]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 09 05:00:49 volumio volumio[515]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Sep 09 05:00:49 volumio volumio[515]: info: Cannot use regular scanning, forcing with ap-force Sep 09 05:00:49 volumio sudo[638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 09 05:00:49 volumio sudo[638]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:49 volumio volumio-remote-updater[840]: [2024-09-09 05:00:49] [connect] Successful connection Sep 09 05:00:51 volumio sudo[638]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:51 volumio volumio[515]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 09 05:00:51 volumio volumio-remote-updater[840]: [2024-09-09 05:00:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725850849 101 Sep 09 05:00:51 volumio volumio[515]: 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: 2 Sep 09 05:00:51 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:51 volumio volumio[515]: info: Reloading queue from file Sep 09 05:00:51 volumio volumio[515]: info: CoreStateMachine::setRepeat false single undefined Sep 09 05:00:51 volumio volumio[515]: info: CoreStateMachine::pushState Sep 09 05:00:51 volumio volumio[515]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:51 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 09 05:00:51 volumio volumio[515]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:51 volumio volumio[515]: info: CoreStateMachine::setRandom null Sep 09 05:00:51 volumio volumio[515]: info: CoreStateMachine::pushState Sep 09 05:00:51 volumio volumio[515]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:51 volumio volumio[515]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:51 volumio volumio[515]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 09 05:00:51 volumio volumio[515]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04170 Sep 09 05:00:51 volumio volumio[515]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 09 05:00:51 volumio volumio[515]: info: Setting Device type: Raspberry PI Sep 09 05:00:51 volumio volumio[515]: info: Completed loading Core Plugins Sep 09 05:00:51 volumio volumio[515]: info: Preparing to generate the ALSA configuration file Sep 09 05:00:51 volumio volumio[515]: info: Asound.conf file unchanged, so no further update is needed Sep 09 05:00:51 volumio volumio[515]: info: Output device has changed, restarting MPD Sep 09 05:00:51 volumio sudo[653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 09 05:00:51 volumio sudo[653]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:51 volumio sudo[653]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:51 volumio volumio[515]: info: Output device has changed, restarting Shairport Sync Sep 09 05:00:51 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:51 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:51 volumio sudo[656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 09 05:00:51 volumio sudo[656]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:51 volumio systemd[1]: Stopping Music Player Daemon... Sep 09 05:00:51 volumio volumio[515]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:51 volumio volumio[515]: info: ___________ START PLUGINS ___________ Sep 09 05:00:51 volumio volumio[515]: info: ControllerMpd::onStart: Initializing MPD Sep 09 05:00:51 volumio volumio[515]: info: Creating MPD Configuration file Sep 09 05:00:51 volumio systemd[1]: mpd.service: Succeeded. Sep 09 05:00:51 volumio systemd[1]: Stopped Music Player Daemon. Sep 09 05:00:51 volumio sudo[663]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 09 05:00:51 volumio sudo[663]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:52 volumio volumio[515]: info: [1725850852000] CoreMusicLibrary::Adding element Media Servers Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:52 volumio sudo[663]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:52 volumio systemd[1]: Starting Music Player Daemon... Sep 09 05:00:52 volumio sudo[667]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 09 05:00:52 volumio sudo[667]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:52 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 09 05:00:52 volumio systemd[1]: mpd.service: Succeeded. Sep 09 05:00:52 volumio systemd[1]: Stopped Music Player Daemon. Sep 09 05:00:52 volumio systemd[1]: Starting Music Player Daemon... Sep 09 05:00:52 volumio volumio[515]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:52 volumio volumio[515]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:52 volumio volumio[515]: info: [1725850852043] CoreMusicLibrary::Adding element Last_100 Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:52 volumio sudo[672]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 09 05:00:52 volumio sudo[672]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:52 volumio volumio[515]: info: [1725850852044] CoreMusicLibrary::Adding element Webradio Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:52 volumio sudo[672]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:52 volumio volumio[515]: info: Initializing BBC Radios Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:52 volumio volumio[515]: info: Creating Spotify config file Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:52 volumio volumio[515]: info: [1725850852097] CoreMusicLibrary::Adding element LastFM Sep 09 05:00:52 volumio volumio[515]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:52 volumio volumio[515]: Cannot find translation for source LastFM Sep 09 05:00:52 volumio volumio[515]: info: [LastFM] scrobbler initiated! Sep 09 05:00:52 volumio volumio[515]: info: [LastFM] extended logging: false Sep 09 05:00:52 volumio volumio[515]: info: [LastFM] try scrobble stream/radio plays: true Sep 09 05:00:52 volumio volumio[515]: info: [LastFM] Left init routine Sep 09 05:00:52 volumio volumio[515]: info: [LastFM] Socket already connected: true Sep 09 05:00:52 volumio volumio[515]: info: Volumio Calling Home Sep 09 05:00:52 volumio volumio[515]: Unhandled rejection Error: No sockets available, cannot start. Sep 09 05:00:52 volumio volumio[515]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Sep 09 05:00:52 volumio volumio[515]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Sep 09 05:00:52 volumio volumio[515]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Sep 09 05:00:52 volumio volumio[515]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Sep 09 05:00:52 volumio volumio[515]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Sep 09 05:00:52 volumio volumio[515]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Sep 09 05:00:52 volumio volumio[515]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Sep 09 05:00:52 volumio volumio[515]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Sep 09 05:00:52 volumio volumio[515]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Sep 09 05:00:52 volumio volumio[515]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Sep 09 05:00:52 volumio volumio[515]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Sep 09 05:00:52 volumio volumio[515]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Sep 09 05:00:52 volumio volumio[515]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Sep 09 05:00:52 volumio volumio[515]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Sep 09 05:00:52 volumio volumio[515]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Sep 09 05:00:52 volumio volumio[515]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Sep 09 05:00:52 volumio volumio[515]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Sep 09 05:00:52 volumio volumio[515]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:00:52 volumio volumio[515]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 09 05:00:52 volumio volumio[515]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 09 05:00:52 volumio volumio[515]: errno: -16, Sep 09 05:00:52 volumio volumio[515]: code: 'EBUSY', Sep 09 05:00:52 volumio volumio[515]: syscall: 'getaddrinfo', Sep 09 05:00:52 volumio volumio[515]: hostname: 'ws.audioscrobbler.com' Sep 09 05:00:52 volumio volumio[515]: } Sep 09 05:00:52 volumio volumio[515]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:00:52 volumio sudo[704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-09 04:59 Sep 09 05:00:52 volumio sudo[704]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:52 volumio mpd[677]: Sep 09 05:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 09 05:00:52 volumio sudo[704]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:52 volumio volumio-remote-updater[840]: [2024-09-09 05:00:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 09 05:00:52 volumio volumio-remote-updater[840]: [2024-09-09 05:00:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 09 05:00:52 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 09 05:00:52 volumio sudo[656]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:52 volumio sudo[667]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:52 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 09 05:00:52 volumio systemd[1]: Started dynamicswap service. Sep 09 05:00:52 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 09 05:00:52 volumio systemd[1]: Started Music Player Daemon. Sep 09 05:00:52 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 09 05:00:52 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Sep 09 05:00:52 volumio systemd[1]: Stopped Volumio Backend Module. Sep 09 05:00:52 volumio systemd[1]: Started Volumio Backend Module. Sep 09 05:00:52 volumio systemd[1]: dynamicswap.service: Start request repeated too quickly. Sep 09 05:00:52 volumio systemd[1]: dynamicswap.service: Failed with result 'start-limit-hit'. Sep 09 05:00:52 volumio systemd[1]: Failed to start dynamicswap service. Sep 09 05:00:52 volumio dhcpcd[1162]: eth0: using IPv4LL address 169.254.235.251 Sep 09 05:00:52 volumio dhcpcd[1162]: eth0: adding route to 169.254.0.0/16 Sep 09 05:00:52 volumio avahi-daemon[833]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.235.251. Sep 09 05:00:52 volumio avahi-daemon[833]: New relevant interface eth0.IPv4 for mDNS. Sep 09 05:00:52 volumio avahi-daemon[833]: Registering new address record for 169.254.235.251 on eth0.IPv4. Sep 09 05:00:52 volumio dhcpcd[1162]: eth0: adding default route Sep 09 05:00:52 volumio volumio[720]: info: ------------------------------------------- Sep 09 05:00:52 volumio volumio[720]: info: ----- Volumio3 ---- Sep 09 05:00:52 volumio volumio[720]: info: ------------------------------------------- Sep 09 05:00:52 volumio volumio[720]: info: ----- System startup ---- Sep 09 05:00:52 volumio volumio[720]: info: ------------------------------------------- Sep 09 05:00:53 volumio volumio[720]: info: MYVOLUMIO Environment detected Sep 09 05:00:53 volumio volumio[720]: info: Plugin folders cleanup Sep 09 05:00:53 volumio volumio[720]: info: Scanning into folder /volumio/app/plugins/ Sep 09 05:00:53 volumio volumio[720]: info: Scanning category audio_interface Sep 09 05:00:53 volumio volumio[720]: info: Scanning category miscellanea Sep 09 05:00:53 volumio volumio[720]: info: Scanning category music_service Sep 09 05:00:53 volumio volumio[720]: info: Scanning category plugins.json Sep 09 05:00:53 volumio volumio[720]: info: Scanning category system_controller Sep 09 05:00:53 volumio volumio[720]: info: Scanning category user_interface Sep 09 05:00:53 volumio volumio[720]: info: Scanning into folder /data/plugins/ Sep 09 05:00:53 volumio volumio[720]: info: Scanning category music_service Sep 09 05:00:53 volumio volumio[720]: info: Scanning category system_controller Sep 09 05:00:53 volumio volumio[720]: info: Scanning category user_interface Sep 09 05:00:53 volumio volumio[720]: info: Plugin folders cleanup completed Sep 09 05:00:53 volumio volumio[720]: info: ------------------------------------------- Sep 09 05:00:53 volumio volumio[720]: info: ----- Core plugins startup ---- Sep 09 05:00:53 volumio volumio[720]: info: ------------------------------------------- Sep 09 05:00:53 volumio volumio[720]: info: Loading plugins from folder /volumio/app/plugins/ Sep 09 05:00:53 volumio volumio[720]: info: Adding plugin upnp to MyMusic Plugins Sep 09 05:00:53 volumio volumio[720]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 09 05:00:53 volumio volumio[720]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 09 05:00:53 volumio volumio[720]: info: Loading plugins from folder /data/plugins/ Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "system"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "appearance"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "network"... Sep 09 05:00:53 volumio volumio[720]: info: Refreshing Cached IP Addresses Sep 09 05:00:53 volumio sudo[752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 09 05:00:53 volumio sudo[752]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:53 volumio sudo[754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 09 05:00:53 volumio sudo[754]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:53 volumio sudo[752]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "services"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "alsa_controller"... Sep 09 05:00:53 volumio sudo[754]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:53 volumio sudo[757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 09 05:00:53 volumio sudo[757]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:53 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "wizard"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "networkfs"... Sep 09 05:00:53 volumio volumio[720]: info: Cannot mount NAS Muziek at system boot, trial number 1 ,retrying in 5 seconds Sep 09 05:00:53 volumio volumio[720]: info: Starting Udev Watcher for removable devices Sep 09 05:00:53 volumio sudo[763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.115/muziek /mnt/NAS/muziek Sep 09 05:00:53 volumio sudo[763]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:53 volumio volumio[720]: info: Ignoring mount for partition: boot Sep 09 05:00:53 volumio volumio[720]: info: Ignoring mount for partition: volumio Sep 09 05:00:53 volumio volumio[720]: info: Ignoring mount for partition: volumio_data Sep 09 05:00:53 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "volumio_command_line_client"... Sep 09 05:00:53 volumio kernel: CIFS: Attempting to mount \\192.168.1.115\muziek Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "upnp"... Sep 09 05:00:53 volumio volumio[720]: info: [1725850853376] Starting Upmpd Daemon Sep 09 05:00:53 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "my_music"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "mpd"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "upnp_browser"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "alarm-clock"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "airplay_emulation"... Sep 09 05:00:53 volumio volumio[720]: info: Starting Shairport Sync Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "last_100"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "webradio"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "i2s_dacs"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "volumiodiscovery"... Sep 09 05:00:53 volumio volumio[720]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:53 volumio node[720]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:53 volumio node[720]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:53 volumio volumio[720]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:53 volumio volumio[720]: *** WARNING *** For more information see Sep 09 05:00:53 volumio volumio[720]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:53 volumio volumio[720]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:53 volumio volumio[720]: *** WARNING *** For more information see Sep 09 05:00:53 volumio node[720]: *** WARNING *** For more information see Sep 09 05:00:53 volumio node[720]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 09 05:00:53 volumio node[720]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 09 05:00:53 volumio node[720]: *** WARNING *** For more information see Sep 09 05:00:53 volumio volumio[720]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 09 05:00:53 volumio volumio[720]: info: Discovery: Started advertising with name: Volumio Sep 09 05:00:53 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "spop"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "outputs"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "albumart"... Sep 09 05:00:53 volumio volumio[720]: info: Plugin example_plugin is not enabled Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "inputs"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "updater_comm"... Sep 09 05:00:53 volumio volumio[720]: info: Plugin mpdemulation is not enabled Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "rest_api"... Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "websocket"... Sep 09 05:00:53 volumio volumio[720]: info: Starting Socket.io Server version 2.3.0 Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "myb"... Sep 09 05:00:53 volumio dhcpcd[1208]: eth0: using IPv4LL address 169.254.235.251 Sep 09 05:00:53 volumio dhcpcd[1208]: eth0: adding route to 169.254.0.0/16 Sep 09 05:00:53 volumio dhcpcd[1208]: eth0: adding default route Sep 09 05:00:53 volumio volumio[720]: Forking 3 albumart workers Sep 09 05:00:53 volumio volumio[720]: info: Applying required configuration parameters for plugin myb Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "backup_restore"... Sep 09 05:00:53 volumio volumio[720]: info: Applying required configuration parameters for plugin backup_restore Sep 09 05:00:53 volumio volumio[720]: info: Loading plugin "Systeminfo"... Sep 09 05:00:54 volumio volumio[720]: info: Loading plugin "lastfm"... Sep 09 05:00:54 volumio volumio[720]: Starting albumart workers Sep 09 05:00:54 volumio volumio[720]: Starting albumart workers Sep 09 05:00:54 volumio volumio[720]: Starting albumart workers Sep 09 05:00:54 volumio volumio[720]: info: Plugin peppyspectrum is not enabled Sep 09 05:00:54 volumio volumio[720]: info: Loading i18n strings for locale nl Sep 09 05:00:54 volumio volumio[720]: Updating browse sources language Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::initPlayerControls Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:54 volumio volumio[720]: Express server listening on port 3000 Sep 09 05:00:54 volumio volumio[720]: [Metrics] WebUI: 1s 447.67ms Sep 09 05:00:54 volumio volumio[720]: info: CoreStateMachine::resetVolumioState Sep 09 05:00:54 volumio volumio[720]: info: CoreStateMachine::getcurrentVolume Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::volumioRetrievevolume Sep 09 05:00:54 volumio volumio[720]: info: CoreStateMachine::pushState Sep 09 05:00:54 volumio volumio[720]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:54 volumio volumio[720]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:54 volumio volumio[720]: info: Reloading queue from file Sep 09 05:00:54 volumio volumio[720]: info: CoreStateMachine::setRepeat false single undefined Sep 09 05:00:54 volumio volumio[720]: info: CoreStateMachine::pushState Sep 09 05:00:54 volumio volumio[720]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:54 volumio volumio[720]: info: CoreStateMachine::setRandom null Sep 09 05:00:54 volumio volumio[720]: info: CoreStateMachine::pushState Sep 09 05:00:54 volumio volumio[720]: info: CorePlayQueue::getTrack 0 Sep 09 05:00:54 volumio volumio[720]: info: CoreCommandRouter::volumioPushState Sep 09 05:00:54 volumio volumio[720]: info: Setting Device type: Raspberry PI Sep 09 05:00:54 volumio volumio[720]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 09 05:00:54 volumio volumio[720]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04170 Sep 09 05:00:54 volumio volumio[720]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 09 05:00:54 volumio ntpd[986]: Listen normally on 9 eth0 169.254.235.251:123 Sep 09 05:00:54 volumio ntpd[986]: new interface(s) found: waking up resolver Sep 09 05:00:54 volumio go-librespot[1463]: time="2024-09-09T05:00:54+02:00" level=error msg="did not receive last pong from dealer, 60s passed" Sep 09 05:00:57 volumio volumio-remote-updater[840]: [2024-09-09 05:00:57] [connect] Successful connection Sep 09 05:00:57 volumio volumio-remote-updater[840]: [2024-09-09 05:00:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725850857 101 Sep 09 05:00:57 volumio volumio[720]: 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: 2 Sep 09 05:00:57 volumio sudo[757]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:58 volumio volumio[720]: info: Cannot mount NAS Muziek at system boot, trial number 2 ,retrying in 5 seconds Sep 09 05:00:58 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="Sist" Sep 09 05:00:58 volumio wpa_supplicant[1095]: wlan0: Trying to associate with SSID 'Sist' Sep 09 05:00:59 volumio ntpd[986]: Soliciting pool server 2001:678:8::123 Sep 09 05:00:59 volumio sudo[763]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio volumio[720]: info: Cannot mount NAS muziek at system boot, trial number 1 ,retrying in 5 seconds Sep 09 05:00:59 volumio volumio[720]: info: Completed loading Core Plugins Sep 09 05:00:59 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Sep 09 05:00:59 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Sep 09 05:00:59 volumio volumio[720]: info: Preparing to generate the ALSA configuration file Sep 09 05:00:59 volumio volumio[720]: info: Asound.conf file unchanged, so no further update is needed Sep 09 05:00:59 volumio volumio[720]: info: Output device has changed, restarting MPD Sep 09 05:00:59 volumio sudo[858]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 09 05:00:59 volumio sudo[858]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio volumio[720]: info: Output device has changed, restarting Shairport Sync Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:59 volumio sudo[858]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio sudo[862]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 09 05:00:59 volumio sudo[862]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio systemd[1]: Stopping Music Player Daemon... Sep 09 05:00:59 volumio volumio[720]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:59 volumio volumio[720]: info: ___________ START PLUGINS ___________ Sep 09 05:00:59 volumio volumio[720]: info: ControllerMpd::onStart: Initializing MPD Sep 09 05:00:59 volumio volumio[720]: info: Creating MPD Configuration file Sep 09 05:00:59 volumio systemd[1]: mpd.service: Succeeded. Sep 09 05:00:59 volumio systemd[1]: Stopped Music Player Daemon. Sep 09 05:00:59 volumio sudo[868]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 09 05:00:59 volumio sudo[868]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio sudo[868]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:59 volumio volumio[720]: info: [1725850859580] CoreMusicLibrary::Adding element Media Servers Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:59 volumio sudo[872]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 09 05:00:59 volumio systemd[1]: Starting Music Player Daemon... Sep 09 05:00:59 volumio sudo[872]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 09 05:00:59 volumio systemd[1]: mpd.service: Succeeded. Sep 09 05:00:59 volumio systemd[1]: Stopped Music Player Daemon. Sep 09 05:00:59 volumio systemd[1]: Starting Music Player Daemon... Sep 09 05:00:59 volumio volumio[720]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:59 volumio volumio[720]: info: [1725850859626] CoreMusicLibrary::Adding element Last_100 Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:59 volumio volumio[720]: info: [1725850859627] CoreMusicLibrary::Adding element Webradio Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:59 volumio volumio[720]: info: Initializing BBC Radios Sep 09 05:00:59 volumio sudo[880]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 09 05:00:59 volumio sudo[880]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio sudo[880]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: Creating Spotify config file Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 09 05:00:59 volumio volumio[720]: info: [1725850859680] CoreMusicLibrary::Adding element LastFM Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 09 05:00:59 volumio volumio[720]: Cannot find translation for source LastFM Sep 09 05:00:59 volumio volumio[720]: info: [LastFM] scrobbler initiated! Sep 09 05:00:59 volumio volumio[720]: info: [LastFM] extended logging: false Sep 09 05:00:59 volumio volumio[720]: info: [LastFM] try scrobble stream/radio plays: true Sep 09 05:00:59 volumio volumio[720]: info: [LastFM] Left init routine Sep 09 05:00:59 volumio volumio[720]: info: [LastFM] Socket already connected: true Sep 09 05:00:59 volumio volumio[720]: info: Volumio Calling Home Sep 09 05:00:59 volumio volumio[720]: info: MPD Permissions set Sep 09 05:00:59 volumio volumio[720]: info: MPD Permissions set Sep 09 05:00:59 volumio volumio[720]: info: Spotify config file written Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio sudo[899]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 09 05:00:59 volumio sudo[899]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio systemd[1]: Stopping go-librespot Daemon... Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 09 05:00:59 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Sep 09 05:00:59 volumio systemd[1]: Stopped go-librespot Daemon. Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:00:59 volumio volumio[720]: info: Starting Shairport Sync Sep 09 05:00:59 volumio volumio[720]: info: Starting Shairport Sync Sep 09 05:00:59 volumio sudo[911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 09 05:00:59 volumio sudo[911]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio systemd[1]: Started go-librespot Daemon. Sep 09 05:00:59 volumio volumio[720]: info: Starting Shairport Sync Sep 09 05:00:59 volumio go-librespot[905]: Librespot-go daemon starting... Sep 09 05:00:59 volumio sudo[899]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 09 05:00:59 volumio go-librespot[905]: time="2024-09-09T05:00:59+02:00" level=info msg="generated new device id: 1ebab2727f4e64d5b829c81a9021c155f17c47fc" Sep 09 05:00:59 volumio go-librespot[905]: time="2024-09-09T05:00:59+02:00" level=debug msg="stored credentials found for johnkooij" Sep 09 05:00:59 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 09 05:00:59 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 09 05:00:59 volumio sudo[922]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 09 05:00:59 volumio sudo[922]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 09 05:00:59 volumio sudo[914]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 09 05:00:59 volumio sudo[914]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:00:59 volumio sudo[911]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio volumio[720]: info: Shairport-Sync Started Sep 09 05:00:59 volumio volumio[720]: Error adding Membership: Error: addMembership EINVAL Sep 09 05:00:59 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 09 05:00:59 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 09 05:00:59 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 09 05:00:59 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 09 05:00:59 volumio sudo[914]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio sudo[922]: pam_unix(sudo:session): session closed for user root Sep 09 05:00:59 volumio volumio[720]: info: Shairport-Sync Started Sep 09 05:00:59 volumio volumio[720]: info: Shairport-Sync Started Sep 09 05:00:59 volumio mpd[891]: Sep 09 05:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 09 05:01:00 volumio systemd[1]: Started Music Player Daemon. Sep 09 05:01:00 volumio sudo[872]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:00 volumio sudo[862]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:00 volumio volumio[720]: info: Completed starting Core Plugins Sep 09 05:01:00 volumio volumio[720]: info: ------------------------------------------- Sep 09 05:01:00 volumio volumio[720]: info: ----- MyVolumio plugins startup ---- Sep 09 05:01:00 volumio volumio[720]: info: ------------------------------------------- Sep 09 05:01:00 volumio volumio[720]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 09 05:01:00 volumio volumio[720]: error: MPD error: The expression evaluated to a falsy value: Sep 09 05:01:00 volumio volumio[720]: assert.ok(self.idling) Sep 09 05:01:00 volumio volumio[720]: error: The expression evaluated to a falsy value: Sep 09 05:01:00 volumio volumio[720]: assert.ok(self.idling) Sep 09 05:01:00 volumio volumio[720]: error: updateQueue error: null Sep 09 05:01:00 volumio volumio[720]: info: MPD running with PID891 Sep 09 05:01:00 volumio volumio[720]: ,establishing connection Sep 09 05:01:00 volumio volumio[720]: error: updateQueue error: null Sep 09 05:01:01 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Sep 09 05:01:01 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Sist" auth_failures=2 duration=23 reason=CONN_FAILED Sep 09 05:01:02 volumio volumio[720]: info: go-librespot daemon successfully initialized Sep 09 05:01:03 volumio volumio[720]: info: Cannot mount NAS Muziek at system boot, trial number 3 ,retrying in 5 seconds Sep 09 05:01:03 volumio sudo[939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 09 05:01:03 volumio sudo[939]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:01:03 volumio sudo[939]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:03 volumio sudo[941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 09 05:01:03 volumio sudo[941]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:01:03 volumio sudo[941]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:03 volumio sudo[945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 09 05:01:03 volumio sudo[945]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:01:03 volumio sudo[945]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:03 volumio volumio[720]: info: Upmpdcli Daemon Started Sep 09 05:01:04 volumio sudo[948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.115/muziek /mnt/NAS/muziek Sep 09 05:01:04 volumio sudo[948]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:01:04 volumio kernel: CIFS: Attempting to mount \\192.168.1.115\muziek Sep 09 05:01:05 volumio volumio[720]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 09 05:01:05 volumio volumio[720]: info: Initializing connection to go-librespot Websocket Sep 09 05:01:08 volumio volumio[720]: info: Cannot mount NAS Muziek at system boot, trial number 4 ,retrying in 5 seconds Sep 09 05:01:10 volumio sudo[948]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:10 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Sep 09 05:01:10 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Sep 09 05:01:10 volumio volumio[720]: info: Cannot mount NAS muziek at system boot, trial number 2 ,retrying in 5 seconds Sep 09 05:01:13 volumio volumio[720]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Sep 09 05:01:15 volumio sudo[953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.115/muziek /mnt/NAS/muziek Sep 09 05:01:15 volumio sudo[953]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:01:15 volumio kernel: CIFS: Attempting to mount \\192.168.1.115\muziek Sep 09 05:01:19 volumio go-librespot[905]: time="2024-09-09T05:01:19+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" Sep 09 05:01:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 09 05:01:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 09 05:01:20 volumio volumio[720]: error: MyVolumio Plugin failed to start in a timely fashion Sep 09 05:01:20 volumio volumio[720]: info: BOOT COMPLETED Sep 09 05:01:20 volumio volumio[720]: [Metrics] CommandRouter: 27s 124.10ms Sep 09 05:01:20 volumio volumio[720]: info: CoreCommandRouter::volumiosetStartupVolume Sep 09 05:01:20 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 09 05:01:20 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:01:20 volumio volumio[720]: info: CoreCommandRouter::Close All Modals sent Sep 09 05:01:20 volumio volumio[720]: info: CoreCommandRouter::Close All Modals sent Sep 09 05:01:21 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 09 05:01:21 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 09 05:01:21 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 09 05:01:21 volumio sudo[953]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:21 volumio volumio[720]: info: Cannot mount NAS muziek at system boot, trial number 3 ,retrying in 5 seconds Sep 09 05:01:21 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Sep 09 05:01:21 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Sep 09 05:01:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 09 05:01:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 09 05:01:23 volumio systemd[1]: Stopped go-librespot Daemon. Sep 09 05:01:23 volumio systemd[1]: Started go-librespot Daemon. Sep 09 05:01:23 volumio go-librespot[961]: Librespot-go daemon starting... Sep 09 05:01:23 volumio go-librespot[961]: time="2024-09-09T05:01:23+02:00" level=info msg="generated new device id: 070319165fe2b775be1bcc409217ffeb47706b1f" Sep 09 05:01:23 volumio go-librespot[961]: time="2024-09-09T05:01:23+02:00" level=debug msg="stored credentials found for johnkooij" Sep 09 05:01:26 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="Sist" Sep 09 05:01:26 volumio wpa_supplicant[1095]: wlan0: Failed to initiate sched scan Sep 09 05:01:26 volumio sudo[970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.115/muziek /mnt/NAS/muziek Sep 09 05:01:26 volumio sudo[970]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:01:26 volumio kernel: CIFS: Attempting to mount \\192.168.1.115\muziek Sep 09 05:01:29 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 09 05:01:29 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 05:01:29 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 09 05:01:29 volumio volumio[720]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.742&uuid=7f4675696d0357ebf1049966cad5f7fd" http://updates.volumio.org/downloader-v1/track-device Sep 09 05:01:29 volumio volumio[720]: % Total % Received % Xferd Average Speed Time Time Time Current Sep 09 05:01:29 volumio volumio[720]: Dload Upload Total Spent Left Speed Sep 09 05:01:29 volumio volumio[720]: [1.6K blob data] Sep 09 05:01:29 volumio volumio[720]: retrying in 5 seconds, trial 0 Sep 09 05:01:29 volumio volumio[720]: info: Volumio Calling Home Sep 09 05:01:30 volumio ntpd[986]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 09 05:01:33 volumio sudo[970]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:33 volumio volumio[720]: info: Cannot mount NAS muziek at system boot, trial number 4 ,retrying in 5 seconds Sep 09 05:01:33 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Sep 09 05:01:33 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Sep 09 05:01:33 volumio wpa_supplicant[1095]: wlan0: Failed to initiate sched scan Sep 09 05:01:34 volumio volumio[720]: info: Discovery: adding 391b63aa-06b7-40f5-b065-86293ca89584 Sep 09 05:01:34 volumio volumio[720]: info: Discovery: Found device Volumio Sep 09 05:01:34 volumio volumio[720]: info: CoreCommandRouter::volumioGetState Sep 09 05:01:34 volumio volumio[720]: info: CorePlayQueue::getTrack 0 Sep 09 05:01:36 volumio volumio[720]: info: Discovery: adding fe49e81a-79ea-4ea6-9271-8f26c5674552 Sep 09 05:01:36 volumio volumio[720]: info: Discovery: Found device Volumio Sep 09 05:01:36 volumio volumio[720]: info: Discovery: Connecting to remote: 169.254.19.233 Sep 09 05:01:36 volumio volumio[720]: info: Discovery: Connected to remote: 169.254.19.233 Sep 09 05:01:38 volumio sudo[980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.115/muziek /mnt/NAS/muziek Sep 09 05:01:38 volumio sudo[980]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 05:01:38 volumio kernel: CIFS: Attempting to mount \\192.168.1.115\muziek Sep 09 05:01:40 volumio volumio[720]: verbose: New Socket.io Connection to 169.254.235.251:3000 from 169.254.198.95 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Sep 09 05:01:40 volumio volumio[720]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Sep 09 05:01:40 volumio volumio[720]: info: CoreCommandRouter::volumioGetState Sep 09 05:01:40 volumio volumio[720]: info: CorePlayQueue::getTrack 0 Sep 09 05:01:41 volumio wpa_supplicant[1095]: wlan0: Failed to initiate sched scan Sep 09 05:01:43 volumio go-librespot[961]: time="2024-09-09T05:01:43+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" Sep 09 05:01:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 09 05:01:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 09 05:01:44 volumio sudo[980]: pam_unix(sudo:session): session closed for user root Sep 09 05:01:44 volumio volumio[720]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Sep 09 05:01:44 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Sep 09 05:01:44 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Sep 09 05:01:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 09 05:01:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 09 05:01:46 volumio systemd[1]: Stopped go-librespot Daemon. Sep 09 05:01:46 volumio systemd[1]: Started go-librespot Daemon. Sep 09 05:01:46 volumio go-librespot[1031]: Librespot-go daemon starting... Sep 09 05:01:46 volumio go-librespot[1031]: time="2024-09-09T05:01:46+02:00" level=info msg="generated new device id: aa636d4587df971249cbdd7a03100029a4b7041c" Sep 09 05:01:46 volumio go-librespot[1031]: time="2024-09-09T05:01:46+02:00" level=debug msg="stored credentials found for johnkooij" Sep 09 05:01:48 volumio wpa_supplicant[1095]: wlan0: Trying to associate with SSID 'Sist' Sep 09 05:01:49 volumio dhcpcd[1208]: eth0: offered 192.168.1.129 from 192.168.1.254 Sep 09 05:01:49 volumio dhcpcd[1208]: eth0: probing address 192.168.1.129/24 Sep 09 05:01:50 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Sep 09 05:01:50 volumio wpa_supplicant[1095]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Sist" auth_failures=3 duration=46 reason=CONN_FAILED Sep 09 05:01:54 volumio volumio[720]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Sep 09 05:01:54 volumio volumio[720]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Sep 09 05:01:55 volumio dhcpcd[1208]: eth0: leased 192.168.1.129 for 86400 seconds Sep 09 05:01:55 volumio dhcpcd[1208]: eth0: adding route to 192.168.1.0/24 Sep 09 05:01:55 volumio avahi-daemon[833]: Registering new address record for 192.168.1.129 on eth0.IPv4. Sep 09 05:01:55 volumio dhcpcd[1208]: eth0: changing default route via 192.168.1.254 Sep 09 05:01:55 volumio dhcpcd[1162]: eth0: pid 1208 deleted default route Sep 09 05:01:55 volumio avahi-daemon[833]: Withdrawing address record for 169.254.235.251 on eth0. Sep 09 05:01:55 volumio avahi-daemon[833]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.235.251. Sep 09 05:01:55 volumio avahi-daemon[833]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.129. Sep 09 05:01:55 volumio dhcpcd[1162]: eth0: pid 1208 deleted IP address 169.254.235.251/16 Sep 09 05:01:55 volumio dhcpcd[1162]: eth0: deleting route to 169.254.0.0/16 Sep 09 05:01:55 volumio dhcpcd[1208]: eth0: deleting route to 169.254.0.0/16 Sep 09 05:01:55 volumio dhcpcd[1208]: eth0: pid 1208 deleted default route via 192.168.1.254 Sep 09 05:01:55 volumio dhcpcd[1162]: eth0: probing for an IPv4LL address Sep 09 05:01:56 volumio ntpd[986]: Listen normally on 10 eth0 192.168.1.129:123 Sep 09 05:01:56 volumio ntpd[986]: Deleting interface #9 eth0, 169.254.235.251#123, interface stats: received=0, sent=7, dropped=0, active_time=62 secs Sep 09 05:01:56 volumio ntpd[986]: 185.224.145.68 local addr 169.254.235.251 -> Sep 09 05:01:56 volumio ntpd[986]: 206.189.110.141 local addr 169.254.235.251 -> Sep 09 05:01:56 volumio ntpd[986]: 178.239.19.59 local addr 169.254.235.251 -> Sep 09 05:01:56 volumio ntpd[986]: 178.239.19.60 local addr 169.254.235.251 -> Sep 09 05:01:56 volumio ntpd[986]: 81.172.225.142 local addr 169.254.235.251 -> Sep 09 05:01:56 volumio ntpd[986]: 45.138.55.61 local addr 169.254.235.251 -> Sep 09 05:01:56 volumio ntpd[986]: 94.198.159.15 local addr 169.254.235.251 -> Sep 09 05:01:56 volumio ntpd[986]: new interface(s) found: waking up resolver Sep 09 05:01:56 volumio ntpd[986]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 09 05:01:56 volumio volumio[720]: info: Discovery: A device disappeared from network Sep 09 05:01:56 volumio volumio[720]: info: Discovery: Device volumio disappeared from network Sep 09 05:01:56 volumio volumio[720]: info: Discovery: Device volumio disappeared from network Sep 09 05:01:56 volumio volumio[720]: info: Discovery: Disconnected from remote: 169.254.19.233 Sep 09 05:01:56 volumio volumio[720]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:01:56 volumio volumio[720]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Sep 09 05:01:56 volumio volumio[720]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 09 05:01:56 volumio volumio[720]: errno: -3007, Sep 09 05:01:56 volumio volumio[720]: code: 'ENOTFOUND', Sep 09 05:01:56 volumio volumio[720]: syscall: 'getaddrinfo', Sep 09 05:01:56 volumio volumio[720]: hostname: 'ws.audioscrobbler.com' Sep 09 05:01:56 volumio volumio[720]: } Sep 09 05:01:56 volumio volumio[720]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 05:01:57 volumio sudo[1108]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-09 05:00 Sep 09 05:01:57 volumio sudo[1108]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"