-- Logs begin at Sat 2025-11-01 18:10:12 AEDT, end at Sat 2025-11-01 18:16:36 AEDT. -- Nov 01 18:15:00 volumio systemd[1]: systemd-timedated.service: Succeeded. Nov 01 18:15:01 volumio volumio[2008]: info: BOOT COMPLETED Nov 01 18:15:03 volumio volumio[2008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:15:03 volumio volumio[2008]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:15:03 volumio volumio[2008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 01 18:15:08 volumio volumio[2008]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:15:08 volumio volumio[2008]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Nov 01 18:15:08 volumio volumio[2008]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Nov 01 18:15:08 volumio volumio[2008]: errno: -3007, Nov 01 18:15:08 volumio volumio[2008]: code: 'ENOTFOUND', Nov 01 18:15:08 volumio volumio[2008]: syscall: 'getaddrinfo', Nov 01 18:15:08 volumio volumio[2008]: hostname: 'ws.audioscrobbler.com' Nov 01 18:15:08 volumio volumio[2008]: } Nov 01 18:15:08 volumio volumio[2008]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:15:08 volumio sudo[2430]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 18:14 Nov 01 18:15:08 volumio sudo[2430]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:15:08 volumio sudo[2430]: pam_unix(sudo:session): session closed for user root Nov 01 18:15:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:15:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:15:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:15:12 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:15:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:15:20 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 2010 ms Nov 01 18:15:22 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 3930 ms Nov 01 18:15:23 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:15:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:15:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:15:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:15:24 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 5930 ms Nov 01 18:15:25 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:15:26 volumio wpa_supplicant[922]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="WiFiFoFum" Nov 01 18:15:26 volumio wpa_supplicant[922]: wlan0: Failed to initiate sched scan Nov 01 18:15:26 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 7930 ms Nov 01 18:15:28 volumio volumio-remote-updater[672]: [2025-11-01 18:15:28] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Nov 01 18:15:28 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 9930 ms Nov 01 18:15:30 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 11940 ms Nov 01 18:15:32 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 13930 ms Nov 01 18:15:33 volumio volumio-remote-updater[672]: [2025-11-01 18:15:33] [connect] Successful connection Nov 01 18:15:34 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 15930 ms Nov 01 18:15:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:15:35 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 16150 ms Nov 01 18:15:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:15:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:15:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:15:36 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:15:36 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 17930 ms Nov 01 18:15:37 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 18160 ms Nov 01 18:15:37 volumio wpa_supplicant[922]: wlan0: Failed to initiate sched scan Nov 01 18:15:38 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 19930 ms Nov 01 18:15:39 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 20170 ms Nov 01 18:15:40 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 21940 ms Nov 01 18:15:41 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 22970 ms Nov 01 18:15:42 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 23930 ms Nov 01 18:15:43 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 24970 ms Nov 01 18:15:44 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 25930 ms Nov 01 18:15:45 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 2 timed out 26970 ms Nov 01 18:15:45 volumio kernel: bcmgenet fd580000.ethernet eth0: NETDEV WATCHDOG: CPU: 3: transmit queue 1 timed out 2010 ms Nov 01 18:15:46 volumio volumio-remote-updater[672]: [2025-11-01 18:15:46] [connect] Successful connection Nov 01 18:15:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:15:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:15:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:15:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:15:48 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:15:48 volumio wpa_supplicant[922]: wlan0: Failed to initiate sched scan Nov 01 18:15:53 volumio ntpd[819]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 01 18:15:54 volumio nmbd[761]: [2025/11/01 18:15:54.492784, 0] ../source3/libsmb/nmblib.c:917(send_udp) Nov 01 18:15:54 volumio nmbd[761]: Packet send failed to 192.168.1.255(138) ERRNO=Network is unreachable Nov 01 18:15:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:15:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:15:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:15:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:15:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:15:59 volumio wpa_supplicant[922]: wlan0: Failed to initiate sched scan Nov 01 18:16:01 volumio volumio-remote-updater[672]: [2025-11-01 18:16:01] [connect] Successful connection Nov 01 18:16:08 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:16:08 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 01 18:16:08 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:08 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:08 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 01 18:16:08 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Nov 01 18:16:08 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:08 volumio systemd[1]: Stopped Volumio Backend Module. Nov 01 18:16:08 volumio systemd[1]: Started Volumio Backend Module. Nov 01 18:16:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:16:08 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:16:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:16:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:16:09 volumio volumio[2579]: info: ------------------------------------------- Nov 01 18:16:09 volumio volumio[2579]: info: ----- Volumio3 ---- Nov 01 18:16:09 volumio volumio[2579]: info: ------------------------------------------- Nov 01 18:16:09 volumio volumio[2579]: info: ----- System startup ---- Nov 01 18:16:09 volumio volumio[2579]: info: ------------------------------------------- Nov 01 18:16:09 volumio volumio[2579]: info: MYVOLUMIO Environment detected Nov 01 18:16:09 volumio volumio[2579]: info: Plugin folders cleanup Nov 01 18:16:09 volumio volumio[2579]: info: Scanning into folder /volumio/app/plugins/ Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category audio_interface Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category miscellanea Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category music_service Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category plugins.json Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category system_controller Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category user_interface Nov 01 18:16:09 volumio volumio[2579]: info: Scanning into folder /data/plugins/ Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category music_service Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category system_controller Nov 01 18:16:09 volumio volumio[2579]: info: Scanning category user_interface Nov 01 18:16:09 volumio volumio[2579]: info: Plugin folders cleanup completed Nov 01 18:16:09 volumio volumio[2579]: info: ------------------------------------------- Nov 01 18:16:09 volumio volumio[2579]: info: ----- Core plugins startup ---- Nov 01 18:16:09 volumio volumio[2579]: info: ------------------------------------------- Nov 01 18:16:09 volumio volumio[2579]: info: Loading plugins from folder /volumio/app/plugins/ Nov 01 18:16:09 volumio volumio[2579]: info: Adding plugin upnp to MyMusic Plugins Nov 01 18:16:09 volumio volumio[2579]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 01 18:16:09 volumio volumio[2579]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 01 18:16:09 volumio volumio[2579]: info: Loading plugins from folder /data/plugins/ Nov 01 18:16:09 volumio volumio[2579]: info: Loading plugin "system"... Nov 01 18:16:09 volumio volumio[2579]: info: Loading plugin "appearance"... Nov 01 18:16:10 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "network"... Nov 01 18:16:10 volumio volumio[2579]: info: Refreshing Cached IP Addresses Nov 01 18:16:10 volumio sudo[2643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:16:10 volumio sudo[2643]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:10 volumio sudo[2643]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:10 volumio sudo[2645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:16:10 volumio sudo[2645]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:10 volumio sudo[2645]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "services"... Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "alsa_controller"... Nov 01 18:16:10 volumio sudo[2654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 01 18:16:10 volumio sudo[2654]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:10 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "wizard"... Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "networkfs"... Nov 01 18:16:10 volumio volumio[2579]: info: Starting Udev Watcher for removable devices Nov 01 18:16:10 volumio volumio[2579]: info: Ignoring mount for partition: boot Nov 01 18:16:10 volumio volumio[2579]: info: Ignoring mount for partition: volumio Nov 01 18:16:10 volumio volumio[2579]: info: Ignoring mount for partition: volumio_data Nov 01 18:16:10 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "volumio_command_line_client"... Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "upnp"... Nov 01 18:16:10 volumio volumio[2579]: info: [1761981370682] Starting Upmpd Daemon Nov 01 18:16:10 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "my_music"... Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "mpd"... Nov 01 18:16:10 volumio volumio[2579]: info: Loading plugin "upnp_browser"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "alarm-clock"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "airplay_emulation"... Nov 01 18:16:11 volumio volumio[2579]: info: Starting Shairport Sync Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "last_100"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "webradio"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "i2s_dacs"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "volumiodiscovery"... Nov 01 18:16:11 volumio volumio[2579]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:11 volumio volumio[2579]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:11 volumio node[2579]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:11 volumio volumio[2579]: *** WARNING *** For more information see Nov 01 18:16:11 volumio volumio[2579]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:11 volumio volumio[2579]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:11 volumio volumio[2579]: *** WARNING *** For more information see Nov 01 18:16:11 volumio node[2579]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:11 volumio node[2579]: *** WARNING *** For more information see Nov 01 18:16:11 volumio node[2579]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:11 volumio node[2579]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:11 volumio node[2579]: *** WARNING *** For more information see Nov 01 18:16:11 volumio volumio[2579]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 18:16:11 volumio volumio[2579]: info: Discovery: Started advertising with name: Volumio Nov 01 18:16:11 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "bandcamp"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "outputs"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "albumart"... Nov 01 18:16:11 volumio volumio[2579]: info: Plugin example_plugin is not enabled Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "inputs"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "updater_comm"... Nov 01 18:16:11 volumio volumio[2579]: info: Plugin mpdemulation is not enabled Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "rest_api"... Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "websocket"... Nov 01 18:16:11 volumio volumio[2579]: info: Starting Socket.io Server version 2.3.0 Nov 01 18:16:11 volumio volumio[2579]: info: Loading plugin "scheduledrestart"... Nov 01 18:16:12 volumio volumio[2579]: Forking 3 albumart workers Nov 01 18:16:12 volumio volumio[2579]: info: Applying required configuration parameters for plugin scheduledrestart Nov 01 18:16:12 volumio volumio[2579]: info: Loading plugin "lastfm"... Nov 01 18:16:12 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Nov 01 18:16:12 volumio dhcpcd[977]: eth0: carrier lost Nov 01 18:16:12 volumio dhcpcd[998]: eth0: carrier lost Nov 01 18:16:12 volumio avahi-daemon[666]: Withdrawing address record for 169.254.71.14 on eth0. Nov 01 18:16:12 volumio dhcpcd[977]: eth0: deleting route to 169.254.0.0/16 Nov 01 18:16:12 volumio avahi-daemon[666]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.71.14. Nov 01 18:16:12 volumio dhcpcd[977]: eth0: deleting default route Nov 01 18:16:12 volumio avahi-daemon[666]: Interface eth0.IPv4 no longer relevant for mDNS. Nov 01 18:16:12 volumio dhcpcd[998]: eth0: deleting route to 169.254.0.0/16 Nov 01 18:16:12 volumio dhcpcd[998]: eth0: deleting default route Nov 01 18:16:12 volumio volumio[2579]: info: Loading i18n strings for locale en Nov 01 18:16:12 volumio volumio[2579]: Updating browse sources language Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:12 volumio volumio[2579]: Starting albumart workers Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::initPlayerControls Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: Express server listening on port 3000 Nov 01 18:16:12 volumio volumio[2579]: [Metrics] WebUI: 3s 468.44ms Nov 01 18:16:12 volumio volumio[2579]: Starting albumart workers Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::resetVolumioState Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::getcurrentVolume Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:12 volumio volumio[2579]: Starting albumart workers Nov 01 18:16:12 volumio volumio[2579]: info: Volumio Network Manager: Network status updated: 1 Nov 01 18:16:12 volumio volumio[2579]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:12 volumio volumio[2579]: info: Reloading queue from file Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::pushState Nov 01 18:16:12 volumio volumio[2579]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::updateTrackBlock Nov 01 18:16:12 volumio volumio[2579]: info: CorePlayQueue::getTrackBlock Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::setRepeat false single undefined Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::pushState Nov 01 18:16:12 volumio volumio[2579]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::setRandom null Nov 01 18:16:12 volumio volumio[2579]: info: CoreStateMachine::pushState Nov 01 18:16:12 volumio volumio[2579]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:12 volumio volumio[2579]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:12 volumio volumio[2579]: info: Setting Device type: Raspberry PI Nov 01 18:16:12 volumio volumio[2579]: info: Completed loading Core Plugins Nov 01 18:16:12 volumio volumio[2579]: info: Preparing to generate the ALSA configuration file Nov 01 18:16:13 volumio volumio[2579]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 01 18:16:13 volumio volumio[2579]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Nov 01 18:16:13 volumio volumio[2579]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 01 18:16:13 volumio ifplugd(eth0)[811]: Link beat lost. Nov 01 18:16:13 volumio volumio[2579]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 01 18:16:13 volumio volumio[2579]: info: Reading ALSA contributions from plugins. Nov 01 18:16:13 volumio volumio[2579]: info: Discovery: A device disappeared from network Nov 01 18:16:13 volumio volumio[2579]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined Nov 01 18:16:13 volumio volumio[2579]: info: CoreStateMachine::pushState Nov 01 18:16:13 volumio volumio[2579]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:13 volumio volumio[2579]: info: Asound.conf file unchanged, so no further update is needed Nov 01 18:16:13 volumio volumio[2579]: info: Output device has changed, restarting MPD Nov 01 18:16:13 volumio volumio[2579]: info: Output device has changed, restarting Shairport Sync Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:13 volumio sudo[2804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:13 volumio sudo[2804]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:13 volumio sudo[2804]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:13 volumio sudo[2810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:13 volumio sudo[2810]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:13 volumio systemd[1]: Stopping Music Player Daemon... Nov 01 18:16:13 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:13 volumio volumio[2579]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:13 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:13 volumio volumio[2579]: info: ___________ START PLUGINS ___________ Nov 01 18:16:13 volumio volumio[2579]: info: ControllerMpd::onStart: Initializing MPD Nov 01 18:16:13 volumio volumio[2579]: info: Creating MPD Configuration file Nov 01 18:16:13 volumio sudo[2828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:13 volumio sudo[2828]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:13 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:13 volumio volumio[2579]: info: [1761981373230] CoreMusicLibrary::Adding element Media Servers Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:13 volumio sudo[2828]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:13 volumio sudo[2830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:13 volumio sudo[2830]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:13 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 01 18:16:13 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:13 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:13 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:13 volumio volumio[2579]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:13 volumio volumio[2579]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:13 volumio volumio[2579]: info: [1761981373315] CoreMusicLibrary::Adding element Last_100 Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:13 volumio volumio[2579]: info: [1761981373317] CoreMusicLibrary::Adding element Webradio Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:13 volumio volumio[2579]: info: Initializing BBC Radios Nov 01 18:16:13 volumio sudo[2837]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 18:16:13 volumio sudo[2837]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:13 volumio sudo[2837]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:13 volumio sudo[2654]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:13 volumio volumio[2579]: info: [1761981373383] CoreMusicLibrary::Adding element Bandcamp Discover Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:13 volumio volumio[2579]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling reboots with hours: 5, minutes: 15 in timezone: Australia/Melbourne Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling job with cron expression: 0 15 5 * * 0 Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling job with cron expression: 0 15 5 * * 1 Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling job with cron expression: 0 15 5 * * 2 Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling job with cron expression: 0 15 5 * * 3 Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling job with cron expression: 0 15 5 * * 4 Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling job with cron expression: 0 15 5 * * 5 Nov 01 18:16:13 volumio volumio[2579]: info: Scheduling job with cron expression: 0 15 5 * * 6 Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:13 volumio volumio[2579]: info: [1761981373440] CoreMusicLibrary::Adding element LastFM Nov 01 18:16:13 volumio volumio[2579]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:13 volumio volumio[2579]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:13 volumio volumio[2579]: Cannot find translation for source LastFM Nov 01 18:16:13 volumio volumio[2579]: info: [LastFM] scrobbler initiated! Nov 01 18:16:13 volumio volumio[2579]: info: [LastFM] extended logging: false Nov 01 18:16:13 volumio volumio[2579]: info: [LastFM] try scrobble stream/radio plays: false Nov 01 18:16:13 volumio volumio[2579]: info: [LastFM] Left init routine Nov 01 18:16:13 volumio volumio[2579]: info: [LastFM] Socket already connected: true Nov 01 18:16:13 volumio volumio[2579]: info: Volumio Calling Home Nov 01 18:16:13 volumio volumio[2579]: Unhandled rejection Error: No sockets available, cannot start. Nov 01 18:16:13 volumio volumio[2579]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 01 18:16:13 volumio volumio[2579]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 01 18:16:13 volumio volumio[2579]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 01 18:16:13 volumio volumio[2579]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 01 18:16:13 volumio volumio[2579]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 01 18:16:13 volumio volumio[2579]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 01 18:16:13 volumio volumio[2579]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 01 18:16:13 volumio volumio[2579]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 01 18:16:13 volumio volumio[2579]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 01 18:16:13 volumio volumio[2579]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 01 18:16:13 volumio volumio[2579]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 01 18:16:13 volumio volumio[2579]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 01 18:16:13 volumio volumio[2579]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 01 18:16:13 volumio volumio[2579]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 01 18:16:13 volumio volumio[2579]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 01 18:16:13 volumio volumio[2579]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 01 18:16:13 volumio volumio[2579]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:13 volumio volumio[2579]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Nov 01 18:16:13 volumio volumio[2579]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Nov 01 18:16:13 volumio volumio[2579]: errno: -16, Nov 01 18:16:13 volumio volumio[2579]: code: 'EBUSY', Nov 01 18:16:13 volumio volumio[2579]: syscall: 'getaddrinfo', Nov 01 18:16:13 volumio volumio[2579]: hostname: 'ws.audioscrobbler.com' Nov 01 18:16:13 volumio volumio[2579]: } Nov 01 18:16:13 volumio volumio[2579]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:13 volumio ntpd[819]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 01 18:16:13 volumio ntpd[819]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 01 18:16:13 volumio ntpd[819]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 01 18:16:13 volumio sudo[2865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 18:15 Nov 01 18:16:13 volumio sudo[2865]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:13 volumio sudo[2865]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:16:14 volumio sudo[2810]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:14 volumio sudo[2830]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 01 18:16:14 volumio mpd[2844]: Nov 01 18:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 18:16:14 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:14 volumio systemd[1]: Started Music Player Daemon. Nov 01 18:16:14 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:14 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 01 18:16:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Nov 01 18:16:14 volumio systemd[1]: Stopped Volumio Backend Module. Nov 01 18:16:14 volumio systemd[1]: Started Volumio Backend Module. Nov 01 18:16:14 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:14 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:14 volumio ntpd[819]: Deleting interface #5 eth0, 169.254.71.14#123, interface stats: received=0, sent=0, dropped=0, active_time=85 secs Nov 01 18:16:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:16:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:16:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:16:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:16:15 volumio volumio[2881]: info: ------------------------------------------- Nov 01 18:16:15 volumio volumio[2881]: info: ----- Volumio3 ---- Nov 01 18:16:15 volumio volumio[2881]: info: ------------------------------------------- Nov 01 18:16:15 volumio volumio[2881]: info: ----- System startup ---- Nov 01 18:16:15 volumio volumio[2881]: info: ------------------------------------------- Nov 01 18:16:15 volumio dhcpcd[977]: eth0: carrier acquired Nov 01 18:16:15 volumio dhcpcd[998]: eth0: carrier acquired Nov 01 18:16:15 volumio dhcpcd[977]: eth0: IAID 32:b3:61:df Nov 01 18:16:15 volumio dhcpcd[998]: eth0: IAID 32:b3:61:df Nov 01 18:16:15 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Nov 01 18:16:15 volumio dhcpcd[977]: eth0: soliciting a DHCP lease Nov 01 18:16:15 volumio dhcpcd[977]: eth0: soliciting an IPv6 router Nov 01 18:16:15 volumio volumio[2881]: info: MYVOLUMIO Environment detected Nov 01 18:16:15 volumio volumio[2881]: info: Plugin folders cleanup Nov 01 18:16:15 volumio volumio[2881]: info: Scanning into folder /volumio/app/plugins/ Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category audio_interface Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category miscellanea Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category music_service Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category plugins.json Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category system_controller Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category user_interface Nov 01 18:16:15 volumio volumio[2881]: info: Scanning into folder /data/plugins/ Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category music_service Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category system_controller Nov 01 18:16:15 volumio volumio[2881]: info: Scanning category user_interface Nov 01 18:16:15 volumio volumio[2881]: info: Plugin folders cleanup completed Nov 01 18:16:15 volumio volumio[2881]: info: ------------------------------------------- Nov 01 18:16:15 volumio volumio[2881]: info: ----- Core plugins startup ---- Nov 01 18:16:15 volumio volumio[2881]: info: ------------------------------------------- Nov 01 18:16:15 volumio volumio[2881]: info: Loading plugins from folder /volumio/app/plugins/ Nov 01 18:16:15 volumio volumio[2881]: info: Adding plugin upnp to MyMusic Plugins Nov 01 18:16:15 volumio volumio[2881]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 01 18:16:15 volumio volumio[2881]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 01 18:16:15 volumio volumio[2881]: info: Loading plugins from folder /data/plugins/ Nov 01 18:16:15 volumio volumio[2881]: info: Loading plugin "system"... Nov 01 18:16:15 volumio volumio[2881]: info: Loading plugin "appearance"... Nov 01 18:16:16 volumio volumio-remote-updater[672]: [2025-11-01 18:16:16] [connect] Successful connection Nov 01 18:16:16 volumio ifplugd(eth0)[811]: Link beat detected. Nov 01 18:16:16 volumio dhcpcd[998]: eth0: soliciting an IPv6 router Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "network"... Nov 01 18:16:16 volumio volumio[2881]: info: Refreshing Cached IP Addresses Nov 01 18:16:16 volumio dhcpcd[998]: eth0: soliciting a DHCP lease Nov 01 18:16:16 volumio sudo[2911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:16:16 volumio sudo[2911]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:16 volumio sudo[2911]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:16 volumio sudo[2913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:16:16 volumio sudo[2913]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:16 volumio sudo[2913]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "services"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "alsa_controller"... Nov 01 18:16:16 volumio sudo[2926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 01 18:16:16 volumio sudo[2926]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:16 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "wizard"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "networkfs"... Nov 01 18:16:16 volumio volumio[2881]: info: Starting Udev Watcher for removable devices Nov 01 18:16:16 volumio volumio[2881]: info: Ignoring mount for partition: boot Nov 01 18:16:16 volumio volumio[2881]: info: Ignoring mount for partition: volumio Nov 01 18:16:16 volumio volumio[2881]: info: Ignoring mount for partition: volumio_data Nov 01 18:16:16 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "volumio_command_line_client"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "upnp"... Nov 01 18:16:16 volumio volumio[2881]: info: [1761981376394] Starting Upmpd Daemon Nov 01 18:16:16 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "my_music"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "mpd"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "upnp_browser"... Nov 01 18:16:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "alarm-clock"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "airplay_emulation"... Nov 01 18:16:16 volumio volumio[2881]: info: Starting Shairport Sync Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "last_100"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "webradio"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "i2s_dacs"... Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "volumiodiscovery"... Nov 01 18:16:16 volumio volumio[2881]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:16 volumio volumio[2881]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:16 volumio volumio[2881]: *** WARNING *** For more information see Nov 01 18:16:16 volumio node[2881]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:16 volumio volumio[2881]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:16 volumio volumio[2881]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:16 volumio volumio[2881]: *** WARNING *** For more information see Nov 01 18:16:16 volumio node[2881]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:16 volumio node[2881]: *** WARNING *** For more information see Nov 01 18:16:16 volumio node[2881]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:16 volumio node[2881]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:16 volumio node[2881]: *** WARNING *** For more information see Nov 01 18:16:16 volumio volumio[2881]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 18:16:16 volumio volumio[2881]: info: Discovery: Started advertising with name: Volumio Nov 01 18:16:16 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:16 volumio volumio[2881]: info: Loading plugin "bandcamp"... Nov 01 18:16:17 volumio wpa_supplicant[922]: wlan0: Trying to associate with SSID 'WiFiFoFum' Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "outputs"... Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "albumart"... Nov 01 18:16:17 volumio sudo[2926]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:17 volumio volumio[2881]: info: Plugin example_plugin is not enabled Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "inputs"... Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "updater_comm"... Nov 01 18:16:17 volumio wpa_supplicant[922]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Nov 01 18:16:17 volumio wpa_supplicant[922]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="WiFiFoFum" auth_failures=3 duration=46 reason=CONN_FAILED Nov 01 18:16:17 volumio volumio[2881]: info: Plugin mpdemulation is not enabled Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "rest_api"... Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "websocket"... Nov 01 18:16:17 volumio volumio[2881]: info: Starting Socket.io Server version 2.3.0 Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "scheduledrestart"... Nov 01 18:16:17 volumio volumio[2881]: Forking 3 albumart workers Nov 01 18:16:17 volumio volumio[2881]: info: Applying required configuration parameters for plugin scheduledrestart Nov 01 18:16:17 volumio volumio[2881]: info: Loading plugin "lastfm"... Nov 01 18:16:18 volumio volumio[2881]: info: Loading i18n strings for locale en Nov 01 18:16:18 volumio volumio[2881]: Updating browse sources language Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::initPlayerControls Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: Express server listening on port 3000 Nov 01 18:16:18 volumio volumio[2881]: [Metrics] WebUI: 3s 359.54ms Nov 01 18:16:18 volumio volumio[2881]: Starting albumart workers Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::resetVolumioState Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::getcurrentVolume Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:18 volumio volumio[2881]: Starting albumart workers Nov 01 18:16:18 volumio volumio[2881]: Starting albumart workers Nov 01 18:16:18 volumio volumio[2881]: info: Volumio Network Manager: Network status updated: 0 Nov 01 18:16:18 volumio volumio-remote-updater[672]: [2025-11-01 18:16:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1761981376 101 Nov 01 18:16:18 volumio volumio[2881]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::pushState Nov 01 18:16:18 volumio volumio[2881]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::updateTrackBlock Nov 01 18:16:18 volumio volumio[2881]: info: CorePlayQueue::getTrackBlock Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:18 volumio volumio[2881]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: Reloading queue from file Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::setRepeat false single undefined Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::pushState Nov 01 18:16:18 volumio volumio[2881]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::setRandom null Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::pushState Nov 01 18:16:18 volumio volumio[2881]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:18 volumio volumio[2881]: info: Setting Device type: Raspberry PI Nov 01 18:16:18 volumio volumio[2881]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 01 18:16:18 volumio volumio[2881]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Nov 01 18:16:18 volumio volumio[2881]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 01 18:16:18 volumio volumio[2881]: info: CoreStateMachine::pushState Nov 01 18:16:18 volumio volumio[2881]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:18 volumio volumio[2881]: info: Completed loading Core Plugins Nov 01 18:16:18 volumio volumio[2881]: info: Preparing to generate the ALSA configuration file Nov 01 18:16:18 volumio volumio[2881]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 01 18:16:18 volumio volumio[2881]: info: Reading ALSA contributions from plugins. Nov 01 18:16:18 volumio volumio[2881]: info: Asound.conf file unchanged, so no further update is needed Nov 01 18:16:18 volumio volumio[2881]: info: Output device has changed, restarting MPD Nov 01 18:16:18 volumio sudo[2994]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:18 volumio sudo[2994]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:18 volumio volumio[2881]: info: Output device has changed, restarting Shairport Sync Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:18 volumio sudo[2994]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:18 volumio sudo[2996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:18 volumio sudo[2996]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:18 volumio systemd[1]: Stopping Music Player Daemon... Nov 01 18:16:18 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:18 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:18 volumio volumio[2881]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:18 volumio volumio[2881]: info: ___________ START PLUGINS ___________ Nov 01 18:16:18 volumio volumio[2881]: info: ControllerMpd::onStart: Initializing MPD Nov 01 18:16:18 volumio volumio[2881]: info: Creating MPD Configuration file Nov 01 18:16:18 volumio sudo[3016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:18 volumio sudo[3016]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:18 volumio volumio[2881]: info: [1761981378854] CoreMusicLibrary::Adding element Media Servers Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:18 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:18 volumio sudo[3016]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:18 volumio sudo[3022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:18 volumio sudo[3022]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:18 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 01 18:16:18 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:18 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:18 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:18 volumio volumio[2881]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:18 volumio volumio[2881]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:18 volumio volumio[2881]: info: [1761981378950] CoreMusicLibrary::Adding element Last_100 Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:18 volumio volumio[2881]: info: [1761981378952] CoreMusicLibrary::Adding element Webradio Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:18 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:18 volumio volumio[2881]: info: Initializing BBC Radios Nov 01 18:16:18 volumio sudo[3028]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 18:16:18 volumio sudo[3028]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:18 volumio sudo[3028]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:19 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:19 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:19 volumio volumio[2881]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:19 volumio volumio[2881]: info: [1761981379013] CoreMusicLibrary::Adding element Bandcamp Discover Nov 01 18:16:19 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:19 volumio volumio[2881]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling reboots with hours: 5, minutes: 15 in timezone: Australia/Melbourne Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling job with cron expression: 0 15 5 * * 0 Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling job with cron expression: 0 15 5 * * 1 Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling job with cron expression: 0 15 5 * * 2 Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling job with cron expression: 0 15 5 * * 3 Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling job with cron expression: 0 15 5 * * 4 Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling job with cron expression: 0 15 5 * * 5 Nov 01 18:16:19 volumio volumio[2881]: info: Scheduling job with cron expression: 0 15 5 * * 6 Nov 01 18:16:19 volumio volumio[2881]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:19 volumio volumio[2881]: info: [1761981379064] CoreMusicLibrary::Adding element LastFM Nov 01 18:16:19 volumio volumio[2881]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:19 volumio volumio[2881]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:19 volumio volumio[2881]: Cannot find translation for source LastFM Nov 01 18:16:19 volumio volumio[2881]: info: [LastFM] scrobbler initiated! Nov 01 18:16:19 volumio volumio[2881]: info: [LastFM] extended logging: false Nov 01 18:16:19 volumio volumio[2881]: info: [LastFM] try scrobble stream/radio plays: false Nov 01 18:16:19 volumio volumio[2881]: info: [LastFM] Left init routine Nov 01 18:16:19 volumio volumio[2881]: info: [LastFM] Socket already connected: true Nov 01 18:16:19 volumio volumio[2881]: info: Volumio Calling Home Nov 01 18:16:19 volumio volumio[2881]: Unhandled rejection Error: No sockets available, cannot start. Nov 01 18:16:19 volumio volumio[2881]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 01 18:16:19 volumio volumio[2881]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 01 18:16:19 volumio volumio[2881]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 01 18:16:19 volumio volumio[2881]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 01 18:16:19 volumio volumio[2881]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 01 18:16:19 volumio volumio[2881]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 01 18:16:19 volumio volumio[2881]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 01 18:16:19 volumio volumio[2881]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 01 18:16:19 volumio volumio[2881]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 01 18:16:19 volumio volumio[2881]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 01 18:16:19 volumio volumio[2881]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 01 18:16:19 volumio volumio[2881]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 01 18:16:19 volumio volumio[2881]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 01 18:16:19 volumio volumio[2881]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 01 18:16:19 volumio volumio[2881]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 01 18:16:19 volumio volumio[2881]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 01 18:16:19 volumio volumio[2881]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:19 volumio volumio[2881]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Nov 01 18:16:19 volumio volumio[2881]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Nov 01 18:16:19 volumio volumio[2881]: errno: -16, Nov 01 18:16:19 volumio volumio[2881]: code: 'EBUSY', Nov 01 18:16:19 volumio volumio[2881]: syscall: 'getaddrinfo', Nov 01 18:16:19 volumio volumio[2881]: hostname: 'ws.audioscrobbler.com' Nov 01 18:16:19 volumio volumio[2881]: } Nov 01 18:16:19 volumio volumio[2881]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:19 volumio sudo[3056]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 18:15 Nov 01 18:16:19 volumio sudo[3056]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:19 volumio sudo[3056]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:19 volumio volumio-remote-updater[672]: [2025-11-01 18:16:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Nov 01 18:16:19 volumio volumio-remote-updater[672]: [2025-11-01 18:16:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Nov 01 18:16:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:16:19 volumio sudo[2996]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:19 volumio sudo[3022]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 01 18:16:19 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:19 volumio mpd[3035]: Nov 01 18:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 18:16:19 volumio systemd[1]: Started Music Player Daemon. Nov 01 18:16:19 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:20 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 01 18:16:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5. Nov 01 18:16:20 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:20 volumio systemd[1]: Stopped Volumio Backend Module. Nov 01 18:16:20 volumio systemd[1]: Started Volumio Backend Module. Nov 01 18:16:20 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:20 volumio dhcpcd[977]: eth0: probing for an IPv4LL address Nov 01 18:16:21 volumio volumio[3073]: info: ------------------------------------------- Nov 01 18:16:21 volumio volumio[3073]: info: ----- Volumio3 ---- Nov 01 18:16:21 volumio volumio[3073]: info: ------------------------------------------- Nov 01 18:16:21 volumio volumio[3073]: info: ----- System startup ---- Nov 01 18:16:21 volumio volumio[3073]: info: ------------------------------------------- Nov 01 18:16:21 volumio dhcpcd[998]: eth0: probing for an IPv4LL address Nov 01 18:16:21 volumio volumio[3073]: info: MYVOLUMIO Environment detected Nov 01 18:16:21 volumio volumio[3073]: info: Plugin folders cleanup Nov 01 18:16:21 volumio volumio[3073]: info: Scanning into folder /volumio/app/plugins/ Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category audio_interface Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category miscellanea Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category music_service Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category plugins.json Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category system_controller Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category user_interface Nov 01 18:16:21 volumio volumio[3073]: info: Scanning into folder /data/plugins/ Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category music_service Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category system_controller Nov 01 18:16:21 volumio volumio[3073]: info: Scanning category user_interface Nov 01 18:16:21 volumio volumio[3073]: info: Plugin folders cleanup completed Nov 01 18:16:21 volumio volumio[3073]: info: ------------------------------------------- Nov 01 18:16:21 volumio volumio[3073]: info: ----- Core plugins startup ---- Nov 01 18:16:21 volumio volumio[3073]: info: ------------------------------------------- Nov 01 18:16:21 volumio volumio[3073]: info: Loading plugins from folder /volumio/app/plugins/ Nov 01 18:16:21 volumio volumio[3073]: info: Adding plugin upnp to MyMusic Plugins Nov 01 18:16:21 volumio volumio[3073]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 01 18:16:21 volumio volumio[3073]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 01 18:16:21 volumio volumio[3073]: info: Loading plugins from folder /data/plugins/ Nov 01 18:16:21 volumio volumio[3073]: info: Loading plugin "system"... Nov 01 18:16:21 volumio volumio[3073]: info: Loading plugin "appearance"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "network"... Nov 01 18:16:22 volumio volumio[3073]: info: Refreshing Cached IP Addresses Nov 01 18:16:22 volumio sudo[3099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:16:22 volumio sudo[3099]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:22 volumio sudo[3099]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:22 volumio sudo[3101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:16:22 volumio sudo[3101]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:22 volumio sudo[3101]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "services"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "alsa_controller"... Nov 01 18:16:22 volumio sudo[3113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 01 18:16:22 volumio sudo[3113]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:22 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "wizard"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "networkfs"... Nov 01 18:16:22 volumio volumio[3073]: info: Starting Udev Watcher for removable devices Nov 01 18:16:22 volumio volumio[3073]: info: Ignoring mount for partition: boot Nov 01 18:16:22 volumio volumio[3073]: info: Ignoring mount for partition: volumio Nov 01 18:16:22 volumio volumio[3073]: info: Ignoring mount for partition: volumio_data Nov 01 18:16:22 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "volumio_command_line_client"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "upnp"... Nov 01 18:16:22 volumio volumio[3073]: info: [1761981382157] Starting Upmpd Daemon Nov 01 18:16:22 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "my_music"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "mpd"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "upnp_browser"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "alarm-clock"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "airplay_emulation"... Nov 01 18:16:22 volumio volumio[3073]: info: Starting Shairport Sync Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "last_100"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "webradio"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "i2s_dacs"... Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "volumiodiscovery"... Nov 01 18:16:22 volumio volumio[3073]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:22 volumio volumio[3073]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:22 volumio node[3073]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:22 volumio volumio[3073]: *** WARNING *** For more information see Nov 01 18:16:22 volumio volumio[3073]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:22 volumio volumio[3073]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:22 volumio volumio[3073]: *** WARNING *** For more information see Nov 01 18:16:22 volumio node[3073]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:22 volumio node[3073]: *** WARNING *** For more information see Nov 01 18:16:22 volumio node[3073]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:22 volumio node[3073]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:22 volumio node[3073]: *** WARNING *** For more information see Nov 01 18:16:22 volumio volumio[3073]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 18:16:22 volumio volumio[3073]: info: Discovery: Started advertising with name: Volumio Nov 01 18:16:22 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:22 volumio volumio[3073]: info: Loading plugin "bandcamp"... Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "outputs"... Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "albumart"... Nov 01 18:16:23 volumio volumio[3073]: info: Plugin example_plugin is not enabled Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "inputs"... Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "updater_comm"... Nov 01 18:16:23 volumio volumio[3073]: info: Plugin mpdemulation is not enabled Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "rest_api"... Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "websocket"... Nov 01 18:16:23 volumio volumio[3073]: info: Starting Socket.io Server version 2.3.0 Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "scheduledrestart"... Nov 01 18:16:23 volumio volumio[3073]: Forking 3 albumart workers Nov 01 18:16:23 volumio volumio[3073]: info: Applying required configuration parameters for plugin scheduledrestart Nov 01 18:16:23 volumio volumio[3073]: info: Loading plugin "lastfm"... Nov 01 18:16:23 volumio volumio[3073]: info: Loading i18n strings for locale en Nov 01 18:16:23 volumio volumio[3073]: Updating browse sources language Nov 01 18:16:23 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::initPlayerControls Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: Express server listening on port 3000 Nov 01 18:16:24 volumio volumio[3073]: [Metrics] WebUI: 3s 369.92ms Nov 01 18:16:24 volumio volumio[3073]: Starting albumart workers Nov 01 18:16:24 volumio volumio[3073]: Starting albumart workers Nov 01 18:16:24 volumio volumio[3073]: Starting albumart workers Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::resetVolumioState Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::getcurrentVolume Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:24 volumio volumio[3073]: info: Volumio Network Manager: Network status updated: 0 Nov 01 18:16:24 volumio volumio[3073]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::pushState Nov 01 18:16:24 volumio volumio[3073]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::updateTrackBlock Nov 01 18:16:24 volumio volumio[3073]: info: CorePlayQueue::getTrackBlock Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: Reloading queue from file Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::setRepeat false single undefined Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::pushState Nov 01 18:16:24 volumio volumio[3073]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::setRandom null Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::pushState Nov 01 18:16:24 volumio volumio[3073]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:24 volumio volumio[3073]: info: Setting Device type: Raspberry PI Nov 01 18:16:24 volumio volumio[3073]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 01 18:16:24 volumio volumio[3073]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Nov 01 18:16:24 volumio volumio[3073]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 01 18:16:24 volumio volumio[3073]: info: Completed loading Core Plugins Nov 01 18:16:24 volumio volumio[3073]: info: Preparing to generate the ALSA configuration file Nov 01 18:16:24 volumio volumio[3073]: info: CoreStateMachine::pushState Nov 01 18:16:24 volumio volumio[3073]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:24 volumio volumio[3073]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 01 18:16:24 volumio volumio[3073]: info: Reading ALSA contributions from plugins. Nov 01 18:16:24 volumio volumio[3073]: info: Asound.conf file unchanged, so no further update is needed Nov 01 18:16:24 volumio volumio[3073]: info: Output device has changed, restarting MPD Nov 01 18:16:24 volumio sudo[3182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:24 volumio sudo[3182]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:24 volumio volumio[3073]: info: Output device has changed, restarting Shairport Sync Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:24 volumio sudo[3192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:24 volumio sudo[3192]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:24 volumio sudo[3182]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:24 volumio systemd[1]: Stopping Music Player Daemon... Nov 01 18:16:24 volumio sudo[3113]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:24 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:24 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:24 volumio volumio[3073]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:24 volumio volumio[3073]: info: ___________ START PLUGINS ___________ Nov 01 18:16:24 volumio volumio[3073]: info: ControllerMpd::onStart: Initializing MPD Nov 01 18:16:24 volumio volumio[3073]: info: Creating MPD Configuration file Nov 01 18:16:24 volumio sudo[3208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:24 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Nov 01 18:16:24 volumio sudo[3208]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:24 volumio volumio[3073]: info: [1761981384623] CoreMusicLibrary::Adding element Media Servers Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:24 volumio sudo[3208]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:24 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:24 volumio dhcpcd[977]: eth0: carrier lost Nov 01 18:16:24 volumio dhcpcd[998]: eth0: carrier lost Nov 01 18:16:24 volumio sudo[3210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:24 volumio sudo[3210]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:24 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 01 18:16:24 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:24 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:24 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:24 volumio volumio-remote-updater[672]: [2025-11-01 18:16:24] [connect] Successful connection Nov 01 18:16:24 volumio volumio[3073]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:24 volumio volumio[3073]: info: [1761981384725] CoreMusicLibrary::Adding element Last_100 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:24 volumio volumio[3073]: info: [1761981384727] CoreMusicLibrary::Adding element Webradio Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:24 volumio volumio[3073]: info: Initializing BBC Radios Nov 01 18:16:24 volumio sudo[3239]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 18:16:24 volumio sudo[3239]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:24 volumio sudo[3239]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:24 volumio volumio[3073]: info: [1761981384795] CoreMusicLibrary::Adding element Bandcamp Discover Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:24 volumio volumio[3073]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling reboots with hours: 5, minutes: 15 in timezone: Australia/Melbourne Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling job with cron expression: 0 15 5 * * 0 Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling job with cron expression: 0 15 5 * * 1 Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling job with cron expression: 0 15 5 * * 2 Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling job with cron expression: 0 15 5 * * 3 Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling job with cron expression: 0 15 5 * * 4 Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling job with cron expression: 0 15 5 * * 5 Nov 01 18:16:24 volumio volumio[3073]: info: Scheduling job with cron expression: 0 15 5 * * 6 Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:24 volumio volumio[3073]: info: [1761981384844] CoreMusicLibrary::Adding element LastFM Nov 01 18:16:24 volumio volumio[3073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:24 volumio volumio[3073]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:24 volumio volumio[3073]: Cannot find translation for source LastFM Nov 01 18:16:24 volumio volumio[3073]: info: [LastFM] scrobbler initiated! Nov 01 18:16:24 volumio volumio[3073]: info: [LastFM] extended logging: false Nov 01 18:16:24 volumio volumio[3073]: info: [LastFM] try scrobble stream/radio plays: false Nov 01 18:16:24 volumio volumio[3073]: info: [LastFM] Left init routine Nov 01 18:16:24 volumio volumio[3073]: info: [LastFM] Socket already connected: true Nov 01 18:16:24 volumio volumio[3073]: info: Volumio Calling Home Nov 01 18:16:24 volumio volumio[3073]: Unhandled rejection Error: No sockets available, cannot start. Nov 01 18:16:24 volumio volumio[3073]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 01 18:16:24 volumio volumio[3073]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 01 18:16:24 volumio volumio[3073]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 01 18:16:24 volumio volumio[3073]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 01 18:16:24 volumio volumio[3073]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 01 18:16:24 volumio volumio[3073]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 01 18:16:24 volumio volumio[3073]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 01 18:16:24 volumio volumio[3073]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 01 18:16:24 volumio volumio[3073]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 01 18:16:24 volumio volumio[3073]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 01 18:16:24 volumio volumio[3073]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 01 18:16:24 volumio volumio[3073]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 01 18:16:24 volumio volumio[3073]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 01 18:16:24 volumio volumio[3073]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 01 18:16:24 volumio volumio[3073]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 01 18:16:24 volumio volumio[3073]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 01 18:16:24 volumio volumio[3073]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:24 volumio volumio[3073]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Nov 01 18:16:24 volumio volumio[3073]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Nov 01 18:16:24 volumio volumio[3073]: errno: -16, Nov 01 18:16:24 volumio volumio[3073]: code: 'EBUSY', Nov 01 18:16:24 volumio volumio[3073]: syscall: 'getaddrinfo', Nov 01 18:16:24 volumio volumio[3073]: hostname: 'ws.audioscrobbler.com' Nov 01 18:16:24 volumio volumio[3073]: } Nov 01 18:16:24 volumio volumio[3073]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:25 volumio ifplugd(eth0)[811]: Link beat lost. Nov 01 18:16:25 volumio sudo[3291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 18:15 Nov 01 18:16:25 volumio sudo[3291]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:25 volumio sudo[3291]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:25 volumio volumio-remote-updater[672]: [2025-11-01 18:16:25] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Nov 01 18:16:25 volumio volumio-remote-updater[672]: [2025-11-01 18:16:25] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Nov 01 18:16:25 volumio volumio-remote-updater[672]: [2025-11-01 18:16:25] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 01 18:16:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:16:25 volumio sudo[3192]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:25 volumio sudo[3210]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 01 18:16:25 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:25 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:25 volumio mpd[3271]: Nov 01 18:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 18:16:25 volumio systemd[1]: Started Music Player Daemon. Nov 01 18:16:25 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 01 18:16:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6. Nov 01 18:16:25 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:25 volumio systemd[1]: Stopped Volumio Backend Module. Nov 01 18:16:25 volumio systemd[1]: Started Volumio Backend Module. Nov 01 18:16:25 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:25 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:16:26 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:16:26 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:16:26 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:16:26 volumio dhcpcd[998]: eth0: carrier acquired Nov 01 18:16:26 volumio dhcpcd[998]: eth0: IAID 32:b3:61:df Nov 01 18:16:26 volumio dhcpcd[977]: eth0: carrier acquired Nov 01 18:16:26 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Nov 01 18:16:26 volumio dhcpcd[977]: eth0: IAID 32:b3:61:df Nov 01 18:16:26 volumio volumio[3307]: info: ------------------------------------------- Nov 01 18:16:26 volumio volumio[3307]: info: ----- Volumio3 ---- Nov 01 18:16:26 volumio volumio[3307]: info: ------------------------------------------- Nov 01 18:16:26 volumio volumio[3307]: info: ----- System startup ---- Nov 01 18:16:26 volumio volumio[3307]: info: ------------------------------------------- Nov 01 18:16:27 volumio dhcpcd[977]: eth0: soliciting an IPv6 router Nov 01 18:16:27 volumio volumio[3307]: info: MYVOLUMIO Environment detected Nov 01 18:16:27 volumio volumio[3307]: info: Plugin folders cleanup Nov 01 18:16:27 volumio volumio[3307]: info: Scanning into folder /volumio/app/plugins/ Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category audio_interface Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category miscellanea Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category music_service Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category plugins.json Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category system_controller Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category user_interface Nov 01 18:16:27 volumio volumio[3307]: info: Scanning into folder /data/plugins/ Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category music_service Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category system_controller Nov 01 18:16:27 volumio volumio[3307]: info: Scanning category user_interface Nov 01 18:16:27 volumio volumio[3307]: info: Plugin folders cleanup completed Nov 01 18:16:27 volumio volumio[3307]: info: ------------------------------------------- Nov 01 18:16:27 volumio volumio[3307]: info: ----- Core plugins startup ---- Nov 01 18:16:27 volumio volumio[3307]: info: ------------------------------------------- Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugins from folder /volumio/app/plugins/ Nov 01 18:16:27 volumio volumio[3307]: info: Adding plugin upnp to MyMusic Plugins Nov 01 18:16:27 volumio volumio[3307]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 01 18:16:27 volumio volumio[3307]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugins from folder /data/plugins/ Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "system"... Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "appearance"... Nov 01 18:16:27 volumio dhcpcd[977]: eth0: soliciting a DHCP lease Nov 01 18:16:27 volumio dhcpcd[998]: eth0: soliciting an IPv6 router Nov 01 18:16:27 volumio ifplugd(eth0)[811]: Link beat detected. Nov 01 18:16:27 volumio dhcpcd[998]: eth0: soliciting a DHCP lease Nov 01 18:16:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "network"... Nov 01 18:16:27 volumio volumio[3307]: info: Refreshing Cached IP Addresses Nov 01 18:16:27 volumio sudo[3335]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:16:27 volumio sudo[3335]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:27 volumio sudo[3335]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:27 volumio sudo[3337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:16:27 volumio sudo[3337]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:27 volumio sudo[3337]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "services"... Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "alsa_controller"... Nov 01 18:16:27 volumio sudo[3346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 01 18:16:27 volumio sudo[3346]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:27 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "wizard"... Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "networkfs"... Nov 01 18:16:27 volumio volumio[3307]: info: Starting Udev Watcher for removable devices Nov 01 18:16:27 volumio volumio[3307]: info: Ignoring mount for partition: boot Nov 01 18:16:27 volumio volumio[3307]: info: Ignoring mount for partition: volumio Nov 01 18:16:27 volumio volumio[3307]: info: Ignoring mount for partition: volumio_data Nov 01 18:16:27 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "volumio_command_line_client"... Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "upnp"... Nov 01 18:16:27 volumio volumio[3307]: info: [1761981387926] Starting Upmpd Daemon Nov 01 18:16:27 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "my_music"... Nov 01 18:16:27 volumio volumio[3307]: info: Loading plugin "mpd"... Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "upnp_browser"... Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "alarm-clock"... Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "airplay_emulation"... Nov 01 18:16:28 volumio volumio[3307]: info: Starting Shairport Sync Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "last_100"... Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "webradio"... Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "i2s_dacs"... Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "volumiodiscovery"... Nov 01 18:16:28 volumio volumio[3307]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:28 volumio volumio[3307]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:28 volumio node[3307]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:28 volumio volumio[3307]: *** WARNING *** For more information see Nov 01 18:16:28 volumio volumio[3307]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:28 volumio volumio[3307]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:28 volumio volumio[3307]: *** WARNING *** For more information see Nov 01 18:16:28 volumio node[3307]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:28 volumio node[3307]: *** WARNING *** For more information see Nov 01 18:16:28 volumio node[3307]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:28 volumio node[3307]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:28 volumio node[3307]: *** WARNING *** For more information see Nov 01 18:16:28 volumio volumio[3307]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 18:16:28 volumio volumio[3307]: info: Discovery: Started advertising with name: Volumio Nov 01 18:16:28 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:28 volumio volumio[3307]: info: Loading plugin "bandcamp"... Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "outputs"... Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "albumart"... Nov 01 18:16:29 volumio volumio[3307]: info: Plugin example_plugin is not enabled Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "inputs"... Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "updater_comm"... Nov 01 18:16:29 volumio volumio[3307]: info: Plugin mpdemulation is not enabled Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "rest_api"... Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "websocket"... Nov 01 18:16:29 volumio volumio[3307]: info: Starting Socket.io Server version 2.3.0 Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "scheduledrestart"... Nov 01 18:16:29 volumio volumio[3307]: Forking 3 albumart workers Nov 01 18:16:29 volumio volumio[3307]: info: Applying required configuration parameters for plugin scheduledrestart Nov 01 18:16:29 volumio volumio[3307]: info: Loading plugin "lastfm"... Nov 01 18:16:29 volumio volumio[3307]: info: Loading i18n strings for locale en Nov 01 18:16:29 volumio volumio[3307]: Updating browse sources language Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:29 volumio volumio[3307]: Starting albumart workers Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::initPlayerControls Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:29 volumio volumio[3307]: Express server listening on port 3000 Nov 01 18:16:29 volumio volumio[3307]: [Metrics] WebUI: 3s 395.27ms Nov 01 18:16:29 volumio volumio[3307]: info: CoreStateMachine::resetVolumioState Nov 01 18:16:29 volumio volumio[3307]: info: CoreStateMachine::getcurrentVolume Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:29 volumio volumio[3307]: Starting albumart workers Nov 01 18:16:29 volumio volumio[3307]: Starting albumart workers Nov 01 18:16:29 volumio volumio[3307]: info: Volumio Network Manager: Network status updated: 0 Nov 01 18:16:29 volumio volumio[3307]: info: CoreStateMachine::pushState Nov 01 18:16:29 volumio volumio[3307]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:29 volumio volumio[3307]: info: CoreStateMachine::updateTrackBlock Nov 01 18:16:29 volumio volumio[3307]: info: CorePlayQueue::getTrackBlock Nov 01 18:16:29 volumio volumio[3307]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:30 volumio volumio[3307]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:30 volumio volumio[3307]: info: Reloading queue from file Nov 01 18:16:30 volumio volumio[3307]: info: CoreStateMachine::pushState Nov 01 18:16:30 volumio volumio[3307]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:30 volumio volumio[3307]: info: CoreStateMachine::setRepeat false single undefined Nov 01 18:16:30 volumio volumio[3307]: info: CoreStateMachine::pushState Nov 01 18:16:30 volumio volumio[3307]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:30 volumio volumio[3307]: info: CoreStateMachine::setRandom null Nov 01 18:16:30 volumio volumio[3307]: info: CoreStateMachine::pushState Nov 01 18:16:30 volumio volumio[3307]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:30 volumio volumio[3307]: info: Setting Device type: Raspberry PI Nov 01 18:16:30 volumio volumio[3307]: info: Completed loading Core Plugins Nov 01 18:16:30 volumio volumio[3307]: info: Preparing to generate the ALSA configuration file Nov 01 18:16:30 volumio volumio[3307]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 01 18:16:30 volumio volumio[3307]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Nov 01 18:16:30 volumio volumio[3307]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 01 18:16:30 volumio volumio[3307]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 01 18:16:30 volumio volumio[3307]: info: Reading ALSA contributions from plugins. Nov 01 18:16:30 volumio volumio[3307]: info: Asound.conf file unchanged, so no further update is needed Nov 01 18:16:30 volumio volumio[3307]: info: Output device has changed, restarting MPD Nov 01 18:16:30 volumio sudo[3434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:30 volumio sudo[3434]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:30 volumio volumio[3307]: info: Output device has changed, restarting Shairport Sync Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:30 volumio sudo[3434]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:30 volumio sudo[3436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:30 volumio sudo[3436]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:30 volumio systemd[1]: Stopping Music Player Daemon... Nov 01 18:16:30 volumio volumio[3307]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:30 volumio volumio[3307]: info: ___________ START PLUGINS ___________ Nov 01 18:16:30 volumio volumio[3307]: info: ControllerMpd::onStart: Initializing MPD Nov 01 18:16:30 volumio volumio[3307]: info: Creating MPD Configuration file Nov 01 18:16:30 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:30 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:30 volumio sudo[3443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:30 volumio volumio[3307]: info: [1761981390407] CoreMusicLibrary::Adding element Media Servers Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:30 volumio volumio[3307]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:30 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:30 volumio sudo[3443]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:30 volumio sudo[3443]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:30 volumio sudo[3446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:30 volumio sudo[3446]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:30 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 01 18:16:30 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:30 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:30 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:30 volumio volumio[3307]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:30 volumio volumio[3307]: info: [1761981390493] CoreMusicLibrary::Adding element Last_100 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:30 volumio volumio[3307]: info: [1761981390495] CoreMusicLibrary::Adding element Webradio Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:30 volumio volumio[3307]: info: Initializing BBC Radios Nov 01 18:16:30 volumio sudo[3455]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 18:16:30 volumio sudo[3455]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:30 volumio sudo[3455]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:30 volumio volumio[3307]: info: [1761981390558] CoreMusicLibrary::Adding element Bandcamp Discover Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:30 volumio volumio[3307]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling reboots with hours: 5, minutes: 15 in timezone: Australia/Melbourne Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling job with cron expression: 0 15 5 * * 0 Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling job with cron expression: 0 15 5 * * 1 Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling job with cron expression: 0 15 5 * * 2 Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling job with cron expression: 0 15 5 * * 3 Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling job with cron expression: 0 15 5 * * 4 Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling job with cron expression: 0 15 5 * * 5 Nov 01 18:16:30 volumio volumio[3307]: info: Scheduling job with cron expression: 0 15 5 * * 6 Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:30 volumio volumio[3307]: info: [1761981390611] CoreMusicLibrary::Adding element LastFM Nov 01 18:16:30 volumio volumio[3307]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:30 volumio volumio[3307]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:30 volumio volumio[3307]: Cannot find translation for source LastFM Nov 01 18:16:30 volumio volumio[3307]: info: [LastFM] scrobbler initiated! Nov 01 18:16:30 volumio volumio[3307]: info: [LastFM] extended logging: false Nov 01 18:16:30 volumio volumio[3307]: info: [LastFM] try scrobble stream/radio plays: false Nov 01 18:16:30 volumio volumio[3307]: info: [LastFM] Left init routine Nov 01 18:16:30 volumio volumio[3307]: info: [LastFM] Socket already connected: true Nov 01 18:16:30 volumio volumio[3307]: info: Volumio Calling Home Nov 01 18:16:30 volumio sudo[3346]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:30 volumio volumio[3307]: Unhandled rejection Error: No sockets available, cannot start. Nov 01 18:16:30 volumio volumio[3307]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 01 18:16:30 volumio volumio[3307]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 01 18:16:30 volumio volumio[3307]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 01 18:16:30 volumio volumio[3307]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 01 18:16:30 volumio volumio[3307]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 01 18:16:30 volumio volumio[3307]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 01 18:16:30 volumio volumio[3307]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 01 18:16:30 volumio volumio[3307]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 01 18:16:30 volumio volumio[3307]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 01 18:16:30 volumio volumio[3307]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 01 18:16:30 volumio volumio[3307]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 01 18:16:30 volumio volumio[3307]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 01 18:16:30 volumio volumio[3307]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 01 18:16:30 volumio volumio[3307]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 01 18:16:30 volumio volumio[3307]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 01 18:16:30 volumio volumio[3307]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 01 18:16:30 volumio volumio[3307]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:30 volumio volumio[3307]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Nov 01 18:16:30 volumio volumio[3307]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Nov 01 18:16:30 volumio volumio[3307]: errno: -16, Nov 01 18:16:30 volumio volumio[3307]: code: 'EBUSY', Nov 01 18:16:30 volumio volumio[3307]: syscall: 'getaddrinfo', Nov 01 18:16:30 volumio volumio[3307]: hostname: 'ws.audioscrobbler.com' Nov 01 18:16:30 volumio volumio[3307]: } Nov 01 18:16:30 volumio volumio[3307]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:31 volumio sudo[3480]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 18:15 Nov 01 18:16:31 volumio sudo[3480]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:31 volumio sudo[3480]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:16:31 volumio sudo[3446]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:31 volumio sudo[3436]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 01 18:16:31 volumio mpd[3464]: Nov 01 18:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 18:16:31 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:31 volumio systemd[1]: Started Music Player Daemon. Nov 01 18:16:31 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:31 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 01 18:16:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7. Nov 01 18:16:31 volumio systemd[1]: Started dynamicswap service. Nov 01 18:16:31 volumio systemd[1]: Stopped Volumio Backend Module. Nov 01 18:16:31 volumio systemd[1]: Started Volumio Backend Module. Nov 01 18:16:31 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:16:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Nov 01 18:16:32 volumio dhcpcd[977]: eth0: probing for an IPv4LL address Nov 01 18:16:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Nov 01 18:16:32 volumio dhcpcd[998]: eth0: probing for an IPv4LL address Nov 01 18:16:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Nov 01 18:16:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Nov 01 18:16:32 volumio volumio[3496]: info: ------------------------------------------- Nov 01 18:16:32 volumio volumio[3496]: info: ----- Volumio3 ---- Nov 01 18:16:32 volumio volumio[3496]: info: ------------------------------------------- Nov 01 18:16:32 volumio volumio[3496]: info: ----- System startup ---- Nov 01 18:16:32 volumio volumio[3496]: info: ------------------------------------------- Nov 01 18:16:32 volumio volumio[3496]: info: MYVOLUMIO Environment detected Nov 01 18:16:32 volumio volumio[3496]: info: Plugin folders cleanup Nov 01 18:16:32 volumio volumio[3496]: info: Scanning into folder /volumio/app/plugins/ Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category audio_interface Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category miscellanea Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category music_service Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category plugins.json Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category system_controller Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category user_interface Nov 01 18:16:32 volumio volumio[3496]: info: Scanning into folder /data/plugins/ Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category music_service Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category system_controller Nov 01 18:16:32 volumio volumio[3496]: info: Scanning category user_interface Nov 01 18:16:32 volumio volumio[3496]: info: Plugin folders cleanup completed Nov 01 18:16:32 volumio volumio[3496]: info: ------------------------------------------- Nov 01 18:16:32 volumio volumio[3496]: info: ----- Core plugins startup ---- Nov 01 18:16:32 volumio volumio[3496]: info: ------------------------------------------- Nov 01 18:16:32 volumio volumio[3496]: info: Loading plugins from folder /volumio/app/plugins/ Nov 01 18:16:32 volumio volumio[3496]: info: Adding plugin upnp to MyMusic Plugins Nov 01 18:16:32 volumio volumio[3496]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 01 18:16:32 volumio volumio[3496]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 01 18:16:32 volumio volumio[3496]: info: Loading plugins from folder /data/plugins/ Nov 01 18:16:32 volumio volumio[3496]: info: Loading plugin "system"... Nov 01 18:16:32 volumio volumio-remote-updater[672]: [2025-11-01 18:16:32] [connect] Successful connection Nov 01 18:16:32 volumio volumio[3496]: info: Loading plugin "appearance"... Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "network"... Nov 01 18:16:33 volumio volumio[3496]: info: Refreshing Cached IP Addresses Nov 01 18:16:33 volumio sudo[3522]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:16:33 volumio sudo[3522]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:33 volumio sudo[3522]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:33 volumio sudo[3524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:16:33 volumio sudo[3524]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:33 volumio sudo[3524]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "services"... Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "alsa_controller"... Nov 01 18:16:33 volumio sudo[3533]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 01 18:16:33 volumio sudo[3533]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:33 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "wizard"... Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "networkfs"... Nov 01 18:16:33 volumio volumio[3496]: info: Starting Udev Watcher for removable devices Nov 01 18:16:33 volumio volumio[3496]: info: Ignoring mount for partition: boot Nov 01 18:16:33 volumio volumio[3496]: info: Ignoring mount for partition: volumio Nov 01 18:16:33 volumio volumio[3496]: info: Ignoring mount for partition: volumio_data Nov 01 18:16:33 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "volumio_command_line_client"... Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "upnp"... Nov 01 18:16:33 volumio volumio[3496]: info: [1761981393679] Starting Upmpd Daemon Nov 01 18:16:33 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "my_music"... Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "mpd"... Nov 01 18:16:33 volumio volumio[3496]: info: Loading plugin "upnp_browser"... Nov 01 18:16:33 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "alarm-clock"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "airplay_emulation"... Nov 01 18:16:34 volumio volumio[3496]: info: Starting Shairport Sync Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "last_100"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "webradio"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "i2s_dacs"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "volumiodiscovery"... Nov 01 18:16:34 volumio volumio[3496]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:34 volumio volumio[3496]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:34 volumio node[3496]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:34 volumio volumio[3496]: *** WARNING *** For more information see Nov 01 18:16:34 volumio volumio[3496]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:34 volumio volumio[3496]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:34 volumio volumio[3496]: *** WARNING *** For more information see Nov 01 18:16:34 volumio node[3496]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:34 volumio node[3496]: *** WARNING *** For more information see Nov 01 18:16:34 volumio node[3496]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:16:34 volumio node[3496]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:16:34 volumio node[3496]: *** WARNING *** For more information see Nov 01 18:16:34 volumio volumio[3496]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 18:16:34 volumio volumio[3496]: info: Discovery: Started advertising with name: Volumio Nov 01 18:16:34 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "bandcamp"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "outputs"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "albumart"... Nov 01 18:16:34 volumio volumio[3496]: info: Plugin example_plugin is not enabled Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "inputs"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "updater_comm"... Nov 01 18:16:34 volumio volumio[3496]: info: Plugin mpdemulation is not enabled Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "rest_api"... Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "websocket"... Nov 01 18:16:34 volumio volumio[3496]: info: Starting Socket.io Server version 2.3.0 Nov 01 18:16:34 volumio volumio[3496]: info: Loading plugin "scheduledrestart"... Nov 01 18:16:35 volumio volumio[3496]: Forking 3 albumart workers Nov 01 18:16:35 volumio volumio[3496]: info: Applying required configuration parameters for plugin scheduledrestart Nov 01 18:16:35 volumio volumio[3496]: info: Loading plugin "lastfm"... Nov 01 18:16:35 volumio volumio[3496]: info: Loading i18n strings for locale en Nov 01 18:16:35 volumio volumio[3496]: Updating browse sources language Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::initPlayerControls Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: Express server listening on port 3000 Nov 01 18:16:35 volumio volumio[3496]: [Metrics] WebUI: 3s 401.20ms Nov 01 18:16:35 volumio volumio[3496]: Starting albumart workers Nov 01 18:16:35 volumio volumio[3496]: Starting albumart workers Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::resetVolumioState Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::getcurrentVolume Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:35 volumio volumio[3496]: Starting albumart workers Nov 01 18:16:35 volumio volumio[3496]: info: Volumio Network Manager: Network status updated: 0 Nov 01 18:16:35 volumio volumio-remote-updater[672]: [2025-11-01 18:16:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1761981392 101 Nov 01 18:16:35 volumio volumio[3496]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Nov 01 18:16:35 volumio volumio[3496]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::pushState Nov 01 18:16:35 volumio volumio[3496]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::updateTrackBlock Nov 01 18:16:35 volumio volumio[3496]: info: CorePlayQueue::getTrackBlock Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:35 volumio volumio[3496]: info: Reloading queue from file Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::setRepeat false single undefined Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::pushState Nov 01 18:16:35 volumio volumio[3496]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::setRandom null Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::pushState Nov 01 18:16:35 volumio volumio[3496]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:35 volumio volumio[3496]: info: Setting Device type: Raspberry PI Nov 01 18:16:35 volumio volumio[3496]: info: Completed loading Core Plugins Nov 01 18:16:35 volumio volumio[3496]: info: Preparing to generate the ALSA configuration file Nov 01 18:16:35 volumio volumio[3496]: info: CoreStateMachine::pushState Nov 01 18:16:35 volumio volumio[3496]: info: CorePlayQueue::getTrack 0 Nov 01 18:16:35 volumio volumio[3496]: info: CoreCommandRouter::volumioPushState Nov 01 18:16:35 volumio volumio[3496]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 01 18:16:35 volumio volumio[3496]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Nov 01 18:16:35 volumio volumio[3496]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 01 18:16:35 volumio volumio[3496]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 01 18:16:35 volumio volumio[3496]: info: Reading ALSA contributions from plugins. Nov 01 18:16:35 volumio volumio[3496]: info: Asound.conf file unchanged, so no further update is needed Nov 01 18:16:35 volumio volumio[3496]: info: Output device has changed, restarting MPD Nov 01 18:16:36 volumio volumio[3496]: info: Output device has changed, restarting Shairport Sync Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:36 volumio sudo[3601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:36 volumio sudo[3601]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:36 volumio dhcpcd[977]: eth0: offered 192.168.1.157 from 192.168.1.1 Nov 01 18:16:36 volumio dhcpcd[998]: eth0: offered 192.168.1.157 from 192.168.1.1 Nov 01 18:16:36 volumio sudo[3601]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:36 volumio sudo[3603]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:36 volumio dhcpcd[977]: eth0: ignoring offer of 192.168.1.157 from 192.168.1.1 Nov 01 18:16:36 volumio dhcpcd[998]: eth0: ignoring offer of 192.168.1.157 from 192.168.1.1 Nov 01 18:16:36 volumio sudo[3603]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:36 volumio systemd[1]: Stopping Music Player Daemon... Nov 01 18:16:36 volumio volumio[3496]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:36 volumio volumio[3496]: info: ___________ START PLUGINS ___________ Nov 01 18:16:36 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:36 volumio volumio[3496]: info: ControllerMpd::onStart: Initializing MPD Nov 01 18:16:36 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:36 volumio volumio[3496]: info: Creating MPD Configuration file Nov 01 18:16:36 volumio sudo[3635]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:16:36 volumio sudo[3635]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:36 volumio volumio[3496]: info: [1761981396157] CoreMusicLibrary::Adding element Media Servers Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:36 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:36 volumio sudo[3635]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:36 volumio sudo[3637]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:16:36 volumio sudo[3637]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:36 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 01 18:16:36 volumio systemd[1]: mpd.service: Succeeded. Nov 01 18:16:36 volumio systemd[1]: Stopped Music Player Daemon. Nov 01 18:16:36 volumio systemd[1]: Starting Music Player Daemon... Nov 01 18:16:36 volumio volumio[3496]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:36 volumio volumio[3496]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:36 volumio volumio[3496]: info: [1761981396255] CoreMusicLibrary::Adding element Last_100 Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:36 volumio volumio[3496]: info: [1761981396257] CoreMusicLibrary::Adding element Webradio Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:36 volumio sudo[3643]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 18:16:36 volumio sudo[3643]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:16:36 volumio volumio[3496]: info: Initializing BBC Radios Nov 01 18:16:36 volumio sudo[3643]: pam_unix(sudo:session): session closed for user root Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:36 volumio volumio[3496]: info: [1761981396321] CoreMusicLibrary::Adding element Bandcamp Discover Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:36 volumio volumio[3496]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling reboots with hours: 5, minutes: 15 in timezone: Australia/Melbourne Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling job with cron expression: 0 15 5 * * 0 Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling job with cron expression: 0 15 5 * * 1 Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling job with cron expression: 0 15 5 * * 2 Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling job with cron expression: 0 15 5 * * 3 Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling job with cron expression: 0 15 5 * * 4 Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling job with cron expression: 0 15 5 * * 5 Nov 01 18:16:36 volumio volumio[3496]: info: Scheduling job with cron expression: 0 15 5 * * 6 Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:16:36 volumio volumio[3496]: info: [1761981396380] CoreMusicLibrary::Adding element LastFM Nov 01 18:16:36 volumio volumio[3496]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:16:36 volumio volumio[3496]: Cannot find translation for source Bandcamp Discover Nov 01 18:16:36 volumio volumio[3496]: Cannot find translation for source LastFM Nov 01 18:16:36 volumio volumio[3496]: info: [LastFM] scrobbler initiated! Nov 01 18:16:36 volumio volumio[3496]: info: [LastFM] extended logging: false Nov 01 18:16:36 volumio volumio[3496]: info: [LastFM] try scrobble stream/radio plays: false Nov 01 18:16:36 volumio volumio[3496]: info: [LastFM] Left init routine Nov 01 18:16:36 volumio volumio[3496]: info: [LastFM] Socket already connected: true Nov 01 18:16:36 volumio volumio[3496]: info: Volumio Calling Home Nov 01 18:16:36 volumio dhcpcd[977]: eth0: using IPv4LL address 169.254.71.14 Nov 01 18:16:36 volumio dhcpcd[977]: eth0: adding route to 169.254.0.0/16 Nov 01 18:16:36 volumio dhcpcd[977]: eth0: adding default route Nov 01 18:16:36 volumio avahi-daemon[666]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.71.14. Nov 01 18:16:36 volumio avahi-daemon[666]: New relevant interface eth0.IPv4 for mDNS. Nov 01 18:16:36 volumio avahi-daemon[666]: Registering new address record for 169.254.71.14 on eth0.IPv4. Nov 01 18:16:36 volumio volumio[3496]: Unhandled rejection Error: No sockets available, cannot start. Nov 01 18:16:36 volumio volumio[3496]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 01 18:16:36 volumio volumio[3496]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 01 18:16:36 volumio volumio[3496]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 01 18:16:36 volumio volumio[3496]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 01 18:16:36 volumio volumio[3496]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 01 18:16:36 volumio volumio[3496]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 01 18:16:36 volumio volumio[3496]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 01 18:16:36 volumio volumio[3496]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 01 18:16:36 volumio volumio[3496]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 01 18:16:36 volumio volumio[3496]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 01 18:16:36 volumio volumio[3496]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 01 18:16:36 volumio volumio[3496]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 01 18:16:36 volumio volumio[3496]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 01 18:16:36 volumio volumio[3496]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 01 18:16:36 volumio volumio[3496]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 01 18:16:36 volumio volumio[3496]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 01 18:16:36 volumio volumio[3496]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:36 volumio volumio[3496]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Nov 01 18:16:36 volumio volumio[3496]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Nov 01 18:16:36 volumio volumio[3496]: errno: -16, Nov 01 18:16:36 volumio volumio[3496]: code: 'EBUSY', Nov 01 18:16:36 volumio volumio[3496]: syscall: 'getaddrinfo', Nov 01 18:16:36 volumio volumio[3496]: hostname: 'ws.audioscrobbler.com' Nov 01 18:16:36 volumio volumio[3496]: } Nov 01 18:16:36 volumio volumio[3496]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:16:36 volumio sudo[3685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 18:15 Nov 01 18:16:36 volumio sudo[3685]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"