-- Logs begin at Sat 2025-01-11 05:26:00 CET, end at Sat 2025-01-11 06:00:35 CET. -- Jan 11 05:59:00 volumio sudo[8727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:58 Jan 11 05:59:00 volumio sudo[8727]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:00 volumio sudo[8727]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 05:59:00 volumio sudo[8700]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:00 volumio sudo[8690]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 05:59:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:00 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:00 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:00 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 05:59:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97474. Jan 11 05:59:00 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 05:59:00 volumio systemd[1]: Started Volumio Backend Module. Jan 11 05:59:00 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:00 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:01 volumio mpd[8717]: Jan 11 05:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 05:59:01 volumio systemd[1]: Started Music Player Daemon. Jan 11 05:59:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:02 volumio volumio[8740]: info: ------------------------------------------- Jan 11 05:59:02 volumio volumio[8740]: info: ----- Volumio3 ---- Jan 11 05:59:02 volumio volumio[8740]: info: ------------------------------------------- Jan 11 05:59:02 volumio volumio[8740]: info: ----- System startup ---- Jan 11 05:59:02 volumio volumio[8740]: info: ------------------------------------------- Jan 11 05:59:03 volumio volumio[8740]: info: MYVOLUMIO Environment detected Jan 11 05:59:03 volumio volumio[8740]: info: Plugin folders cleanup Jan 11 05:59:03 volumio volumio[8740]: info: Scanning into folder /volumio/app/plugins/ Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category audio_interface Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category miscellanea Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category music_service Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category plugins.json Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category system_controller Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category user_interface Jan 11 05:59:03 volumio volumio[8740]: info: Scanning into folder /data/plugins/ Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category system_controller Jan 11 05:59:03 volumio volumio[8740]: info: Scanning category user_interface Jan 11 05:59:03 volumio volumio[8740]: info: Plugin folders cleanup completed Jan 11 05:59:03 volumio volumio[8740]: info: ------------------------------------------- Jan 11 05:59:03 volumio volumio[8740]: info: ----- Core plugins startup ---- Jan 11 05:59:03 volumio volumio[8740]: info: ------------------------------------------- Jan 11 05:59:03 volumio volumio[8740]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 05:59:03 volumio volumio[8740]: info: Adding plugin upnp to MyMusic Plugins Jan 11 05:59:03 volumio volumio[8740]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 05:59:03 volumio volumio[8740]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 05:59:03 volumio volumio[8740]: info: Loading plugins from folder /data/plugins/ Jan 11 05:59:03 volumio volumio[8740]: info: Loading plugin "system"... Jan 11 05:59:03 volumio volumio[8740]: info: Loading plugin "appearance"... Jan 11 05:59:04 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "network"... Jan 11 05:59:04 volumio volumio[8740]: info: Refreshing Cached IP Addresses Jan 11 05:59:04 volumio sudo[8807]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 05:59:04 volumio sudo[8807]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:04 volumio sudo[8807]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:04 volumio sudo[8809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 05:59:04 volumio sudo[8809]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:04 volumio sudo[8809]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "services"... Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "alsa_controller"... Jan 11 05:59:04 volumio sudo[8822]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 05:59:04 volumio sudo[8822]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:04 volumio sudo[8822]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:04 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "wizard"... Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "networkfs"... Jan 11 05:59:04 volumio volumio[8740]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 05:59:04 volumio volumio[8740]: info: Starting Udev Watcher for removable devices Jan 11 05:59:04 volumio volumio[8740]: info: Ignoring mount for partition: boot Jan 11 05:59:04 volumio volumio[8740]: info: Ignoring mount for partition: volumio Jan 11 05:59:04 volumio volumio[8740]: info: Ignoring mount for partition: volumio_data Jan 11 05:59:04 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "volumio_command_line_client"... Jan 11 05:59:04 volumio volumio[8740]: info: Plugin upnp is not enabled Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "my_music"... Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "mpd"... Jan 11 05:59:04 volumio volumio[8740]: info: Plugin upnp_browser is not enabled Jan 11 05:59:04 volumio volumio[8740]: info: Loading plugin "alarm-clock"... Jan 11 05:59:05 volumio volumio[8740]: info: Plugin airplay_emulation is not enabled Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "last_100"... Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "webradio"... Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "i2s_dacs"... Jan 11 05:59:05 volumio volumio[8740]: info: I2S DAC not set, start Auto-detection Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "volumiodiscovery"... Jan 11 05:59:05 volumio volumio[8740]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:05 volumio volumio[8740]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:05 volumio volumio[8740]: *** WARNING *** For more information see Jan 11 05:59:05 volumio node[8740]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:05 volumio volumio[8740]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:05 volumio volumio[8740]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:05 volumio volumio[8740]: *** WARNING *** For more information see Jan 11 05:59:05 volumio node[8740]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:05 volumio node[8740]: *** WARNING *** For more information see Jan 11 05:59:05 volumio node[8740]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:05 volumio node[8740]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:05 volumio node[8740]: *** WARNING *** For more information see Jan 11 05:59:05 volumio volumio[8740]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 05:59:05 volumio volumio[8740]: info: Discovery: Started advertising with name: Volumio Jan 11 05:59:05 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "autostart"... Jan 11 05:59:05 volumio volumio[8740]: info: Applying required configuration parameters for plugin autostart Jan 11 05:59:05 volumio volumio[8740]: info: AutoStart - onVolumioStart - read config.json Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "outputs"... Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "albumart"... Jan 11 05:59:05 volumio volumio[8740]: info: Plugin example_plugin is not enabled Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "inputs"... Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "updater_comm"... Jan 11 05:59:05 volumio volumio[8740]: info: Plugin mpdemulation is not enabled Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "rest_api"... Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "websocket"... Jan 11 05:59:05 volumio volumio[8740]: info: Starting Socket.io Server version 2.3.0 Jan 11 05:59:05 volumio volumio[8740]: info: Loading plugin "backup_restore"... Jan 11 05:59:05 volumio volumio[8740]: Forking 3 albumart workers Jan 11 05:59:06 volumio volumio[8740]: info: Applying required configuration parameters for plugin backup_restore Jan 11 05:59:06 volumio volumio[8740]: info: Loading plugin "Systeminfo"... Jan 11 05:59:06 volumio volumio[8740]: info: Loading plugin "lastfm"... Jan 11 05:59:06 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:06 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:06 volumio ntpd[727]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 11 05:59:06 volumio volumio[8740]: Starting albumart workers Jan 11 05:59:06 volumio volumio[8740]: Starting albumart workers Jan 11 05:59:06 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:07 volumio volumio[8740]: Starting albumart workers Jan 11 05:59:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:07 volumio volumio[8740]: info: Loading plugin "randomizer"... Jan 11 05:59:07 volumio volumio[8740]: info: Applying required configuration parameters for plugin randomizer Jan 11 05:59:07 volumio volumio[8740]: info: Loading i18n strings for locale en Jan 11 05:59:07 volumio volumio[8740]: Updating browse sources language Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::initPlayerControls Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:07 volumio volumio[8740]: Express server listening on port 3000 Jan 11 05:59:07 volumio volumio[8740]: [Metrics] WebUI: 5s 899.47ms Jan 11 05:59:08 volumio volumio[8740]: info: CoreStateMachine::resetVolumioState Jan 11 05:59:08 volumio volumio[8740]: info: CoreStateMachine::getcurrentVolume Jan 11 05:59:08 volumio volumio[8740]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:08 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:08 volumio volumio[8740]: info: Volumio Network Manager: Network status updated: 0 Jan 11 05:59:08 volumio volumio[8740]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 05:59:08 volumio volumio[8740]: wlan0 Interface doesn't support scanning : Device or resource busy Jan 11 05:59:08 volumio volumio[8740]: info: Cannot use regular scanning, forcing with ap-force Jan 11 05:59:08 volumio sudo[8896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 05:59:08 volumio sudo[8896]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:08 volumio volumio-remote-updater[569]: [2025-01-11 05:59:08] [connect] Successful connection Jan 11 05:59:08 volumio wpa_supplicant[847]: wlan0: Failed to initiate sched scan Jan 11 05:59:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:11 volumio sudo[8896]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:11 volumio volumio[8740]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Jan 11 05:59:11 volumio volumio[8740]: info: CoreStateMachine::pushState Jan 11 05:59:11 volumio volumio[8740]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:11 volumio volumio[8740]: info: CoreStateMachine::updateTrackBlock Jan 11 05:59:11 volumio volumio[8740]: info: CorePlayQueue::getTrackBlock Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:11 volumio volumio[8740]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 11 05:59:11 volumio volumio-remote-updater[569]: [2025-01-11 05:59:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736571548 101 Jan 11 05:59:11 volumio volumio[8740]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 2 Jan 11 05:59:11 volumio volumio[8740]: info: CoreStateMachine::pushState Jan 11 05:59:11 volumio volumio[8740]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:11 volumio volumio[8740]: info: CoreStateMachine::setRepeat true single undefined Jan 11 05:59:11 volumio volumio[8740]: info: CoreStateMachine::pushState Jan 11 05:59:11 volumio volumio[8740]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:11 volumio volumio[8740]: info: CoreStateMachine::setRandom true Jan 11 05:59:11 volumio volumio[8740]: info: CoreStateMachine::pushState Jan 11 05:59:11 volumio volumio[8740]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:11 volumio volumio[8740]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:11 volumio volumio[8740]: info: Setting Device type: Raspberry PI Jan 11 05:59:11 volumio volumio[8740]: info: Completed loading Core Plugins Jan 11 05:59:11 volumio volumio[8740]: info: Preparing to generate the ALSA configuration file Jan 11 05:59:11 volumio volumio[8740]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 05:59:11 volumio volumio[8740]: info: Reading ALSA contributions from plugins. Jan 11 05:59:11 volumio volumio[8740]: info: Asound.conf file unchanged, so no further update is needed Jan 11 05:59:11 volumio volumio[8740]: info: Output device has changed, restarting MPD Jan 11 05:59:11 volumio sudo[8912]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:11 volumio sudo[8912]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:11 volumio volumio[8740]: info: ___________ START PLUGINS ___________ Jan 11 05:59:11 volumio sudo[8912]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:11 volumio volumio[8740]: info: ControllerMpd::onStart: Initializing MPD Jan 11 05:59:11 volumio volumio[8740]: info: Creating MPD Configuration file Jan 11 05:59:11 volumio sudo[8914]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:11 volumio sudo[8914]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:12 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 05:59:12 volumio sudo[8918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:12 volumio sudo[8918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:12 volumio volumio[8740]: info: [1736571552018] CoreMusicLibrary::Adding element Last_100 Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:12 volumio sudo[8918]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:12 volumio sudo[8920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:12 volumio volumio[8740]: info: [1736571552039] CoreMusicLibrary::Adding element Webradio Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:12 volumio sudo[8920]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:12 volumio volumio[8740]: info: Initializing BBC Radios Jan 11 05:59:12 volumio systemd[1]: mpd.service: Succeeded. Jan 11 05:59:12 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:12 volumio volumio[8740]: info: AutoStart - onStart Jan 11 05:59:12 volumio systemd[1]: Starting Music Player Daemon... Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:12 volumio volumio[8740]: info: [1736571552141] CoreMusicLibrary::Adding element LastFM Jan 11 05:59:12 volumio volumio[8740]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:12 volumio volumio[8740]: Cannot find translation for source LastFM Jan 11 05:59:12 volumio volumio[8740]: info: [LastFM] scrobbler initiated! Jan 11 05:59:12 volumio volumio[8740]: info: [LastFM] extended logging: false Jan 11 05:59:12 volumio volumio[8740]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 05:59:12 volumio volumio[8740]: info: [LastFM] Left init routine Jan 11 05:59:12 volumio volumio[8740]: info: [LastFM] Socket already connected: true Jan 11 05:59:12 volumio volumio[8740]: info: Volumio Calling Home Jan 11 05:59:12 volumio sudo[8926]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 05:59:12 volumio sudo[8926]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:12 volumio sudo[8926]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:12 volumio volumio[8740]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:12 volumio volumio[8740]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 05:59:12 volumio volumio[8740]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 05:59:12 volumio volumio[8740]: errno: -16, Jan 11 05:59:12 volumio volumio[8740]: code: 'EBUSY', Jan 11 05:59:12 volumio volumio[8740]: syscall: 'getaddrinfo', Jan 11 05:59:12 volumio volumio[8740]: hostname: 'ws.audioscrobbler.com' Jan 11 05:59:12 volumio volumio[8740]: } Jan 11 05:59:12 volumio volumio[8740]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:12 volumio sudo[8948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:58 Jan 11 05:59:12 volumio sudo[8948]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:13 volumio sudo[8948]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:13 volumio volumio-remote-updater[569]: [2025-01-11 05:59:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 05:59:13 volumio volumio-remote-updater[569]: [2025-01-11 05:59:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 05:59:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 05:59:13 volumio sudo[8920]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:13 volumio sudo[8914]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 05:59:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:13 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:13 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:13 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 05:59:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97475. Jan 11 05:59:13 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:13 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 05:59:13 volumio systemd[1]: Started Volumio Backend Module. Jan 11 05:59:13 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:13 volumio mpd[8938]: Jan 11 05:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 05:59:14 volumio systemd[1]: Started Music Player Daemon. Jan 11 05:59:14 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 05:59:15 volumio volumio[8962]: info: ------------------------------------------- Jan 11 05:59:15 volumio volumio[8962]: info: ----- Volumio3 ---- Jan 11 05:59:15 volumio volumio[8962]: info: ------------------------------------------- Jan 11 05:59:15 volumio volumio[8962]: info: ----- System startup ---- Jan 11 05:59:15 volumio volumio[8962]: info: ------------------------------------------- Jan 11 05:59:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:15 volumio volumio[8962]: info: MYVOLUMIO Environment detected Jan 11 05:59:15 volumio volumio[8962]: info: Plugin folders cleanup Jan 11 05:59:15 volumio volumio[8962]: info: Scanning into folder /volumio/app/plugins/ Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category audio_interface Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category miscellanea Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category music_service Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category plugins.json Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category system_controller Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category user_interface Jan 11 05:59:15 volumio volumio[8962]: info: Scanning into folder /data/plugins/ Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category system_controller Jan 11 05:59:15 volumio volumio[8962]: info: Scanning category user_interface Jan 11 05:59:15 volumio volumio[8962]: info: Plugin folders cleanup completed Jan 11 05:59:15 volumio volumio[8962]: info: ------------------------------------------- Jan 11 05:59:15 volumio volumio[8962]: info: ----- Core plugins startup ---- Jan 11 05:59:15 volumio volumio[8962]: info: ------------------------------------------- Jan 11 05:59:15 volumio volumio[8962]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 05:59:15 volumio volumio[8962]: info: Adding plugin upnp to MyMusic Plugins Jan 11 05:59:15 volumio volumio[8962]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 05:59:15 volumio volumio[8962]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 05:59:15 volumio volumio[8962]: info: Loading plugins from folder /data/plugins/ Jan 11 05:59:15 volumio volumio[8962]: info: Loading plugin "system"... Jan 11 05:59:15 volumio volumio[8962]: info: Loading plugin "appearance"... Jan 11 05:59:16 volumio volumio[8962]: info: Loading plugin "network"... Jan 11 05:59:16 volumio volumio[8962]: info: Refreshing Cached IP Addresses Jan 11 05:59:16 volumio sudo[8990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 05:59:16 volumio sudo[8990]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:16 volumio sudo[8990]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:16 volumio sudo[8992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 05:59:16 volumio sudo[8992]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:16 volumio sudo[8992]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:16 volumio volumio[8962]: info: Loading plugin "services"... Jan 11 05:59:16 volumio volumio[8962]: info: Loading plugin "alsa_controller"... Jan 11 05:59:16 volumio sudo[9005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 05:59:16 volumio sudo[9005]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:16 volumio sudo[9005]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:16 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:16 volumio volumio[8962]: info: Loading plugin "wizard"... Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "networkfs"... Jan 11 05:59:17 volumio volumio[8962]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 05:59:17 volumio volumio[8962]: info: Starting Udev Watcher for removable devices Jan 11 05:59:17 volumio volumio[8962]: info: Ignoring mount for partition: boot Jan 11 05:59:17 volumio volumio[8962]: info: Ignoring mount for partition: volumio Jan 11 05:59:17 volumio volumio[8962]: info: Ignoring mount for partition: volumio_data Jan 11 05:59:17 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "volumio_command_line_client"... Jan 11 05:59:17 volumio volumio[8962]: info: Plugin upnp is not enabled Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "my_music"... Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "mpd"... Jan 11 05:59:17 volumio volumio[8962]: info: Plugin upnp_browser is not enabled Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "alarm-clock"... Jan 11 05:59:17 volumio volumio[8962]: info: Plugin airplay_emulation is not enabled Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "last_100"... Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "webradio"... Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "i2s_dacs"... Jan 11 05:59:17 volumio volumio[8962]: info: I2S DAC not set, start Auto-detection Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "volumiodiscovery"... Jan 11 05:59:17 volumio volumio[8962]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:17 volumio volumio[8962]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:17 volumio volumio[8962]: *** WARNING *** For more information see Jan 11 05:59:17 volumio node[8962]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:17 volumio volumio[8962]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:17 volumio volumio[8962]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:17 volumio volumio[8962]: *** WARNING *** For more information see Jan 11 05:59:17 volumio node[8962]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:17 volumio node[8962]: *** WARNING *** For more information see Jan 11 05:59:17 volumio node[8962]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:17 volumio node[8962]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:17 volumio node[8962]: *** WARNING *** For more information see Jan 11 05:59:17 volumio volumio[8962]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 05:59:17 volumio volumio[8962]: info: Discovery: Started advertising with name: Volumio Jan 11 05:59:17 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "autostart"... Jan 11 05:59:17 volumio volumio[8962]: info: Applying required configuration parameters for plugin autostart Jan 11 05:59:17 volumio volumio[8962]: info: AutoStart - onVolumioStart - read config.json Jan 11 05:59:17 volumio volumio[8962]: info: Loading plugin "outputs"... Jan 11 05:59:18 volumio volumio[8962]: info: Loading plugin "albumart"... Jan 11 05:59:18 volumio volumio[8962]: info: Plugin example_plugin is not enabled Jan 11 05:59:18 volumio volumio[8962]: info: Loading plugin "inputs"... Jan 11 05:59:18 volumio volumio[8962]: info: Loading plugin "updater_comm"... Jan 11 05:59:18 volumio volumio-remote-updater[569]: [2025-01-11 05:59:18] [connect] Successful connection Jan 11 05:59:18 volumio volumio[8962]: info: Plugin mpdemulation is not enabled Jan 11 05:59:18 volumio volumio[8962]: info: Loading plugin "rest_api"... Jan 11 05:59:18 volumio volumio[8962]: info: Loading plugin "websocket"... Jan 11 05:59:18 volumio volumio[8962]: info: Starting Socket.io Server version 2.3.0 Jan 11 05:59:18 volumio volumio[8962]: info: Loading plugin "backup_restore"... Jan 11 05:59:18 volumio volumio[8962]: Forking 3 albumart workers Jan 11 05:59:18 volumio volumio[8962]: info: Applying required configuration parameters for plugin backup_restore Jan 11 05:59:18 volumio volumio[8962]: info: Loading plugin "Systeminfo"... Jan 11 05:59:19 volumio volumio[8962]: info: Loading plugin "lastfm"... Jan 11 05:59:19 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 05:59:19 volumio volumio[8962]: Starting albumart workers Jan 11 05:59:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:19 volumio volumio[8962]: Starting albumart workers Jan 11 05:59:19 volumio volumio[8962]: Starting albumart workers Jan 11 05:59:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:19 volumio volumio[8962]: info: Loading plugin "randomizer"... Jan 11 05:59:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:20 volumio volumio[8962]: info: Applying required configuration parameters for plugin randomizer Jan 11 05:59:20 volumio volumio[8962]: info: Loading i18n strings for locale en Jan 11 05:59:20 volumio volumio[8962]: Updating browse sources language Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::initPlayerControls Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: Express server listening on port 3000 Jan 11 05:59:20 volumio volumio[8962]: [Metrics] WebUI: 5s 897.76ms Jan 11 05:59:20 volumio volumio[8962]: info: CoreStateMachine::resetVolumioState Jan 11 05:59:20 volumio volumio[8962]: info: CoreStateMachine::getcurrentVolume Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:20 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:20 volumio volumio[8962]: info: Volumio Network Manager: Network status updated: 0 Jan 11 05:59:20 volumio volumio[8962]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 05:59:20 volumio volumio[8962]: wlan0 Interface doesn't support scanning : Device or resource busy Jan 11 05:59:20 volumio volumio[8962]: info: Cannot use regular scanning, forcing with ap-force Jan 11 05:59:20 volumio sudo[9082]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 05:59:20 volumio sudo[9082]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:21 volumio wpa_supplicant[847]: wlan0: Failed to initiate sched scan Jan 11 05:59:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:24 volumio sudo[9082]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:24 volumio volumio[8962]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Jan 11 05:59:24 volumio volumio[8962]: info: CoreStateMachine::pushState Jan 11 05:59:24 volumio volumio[8962]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:24 volumio volumio[8962]: info: CoreStateMachine::updateTrackBlock Jan 11 05:59:24 volumio volumio[8962]: info: CorePlayQueue::getTrackBlock Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:24 volumio volumio[8962]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 11 05:59:24 volumio volumio[8962]: info: CoreStateMachine::pushState Jan 11 05:59:24 volumio volumio[8962]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:24 volumio volumio[8962]: info: CoreStateMachine::setRepeat true single undefined Jan 11 05:59:24 volumio volumio[8962]: info: CoreStateMachine::pushState Jan 11 05:59:24 volumio volumio[8962]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:24 volumio volumio[8962]: info: CoreStateMachine::setRandom true Jan 11 05:59:24 volumio volumio[8962]: info: CoreStateMachine::pushState Jan 11 05:59:24 volumio volumio[8962]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:24 volumio volumio[8962]: info: Setting Device type: Raspberry PI Jan 11 05:59:24 volumio volumio[8962]: info: Completed loading Core Plugins Jan 11 05:59:24 volumio volumio[8962]: info: Preparing to generate the ALSA configuration file Jan 11 05:59:24 volumio volumio[8962]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 05:59:24 volumio volumio[8962]: info: Reading ALSA contributions from plugins. Jan 11 05:59:24 volumio volumio[8962]: info: Asound.conf file unchanged, so no further update is needed Jan 11 05:59:24 volumio volumio[8962]: info: Output device has changed, restarting MPD Jan 11 05:59:24 volumio sudo[9095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:24 volumio sudo[9095]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:24 volumio volumio[8962]: info: ___________ START PLUGINS ___________ Jan 11 05:59:24 volumio sudo[9095]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:24 volumio volumio[8962]: info: ControllerMpd::onStart: Initializing MPD Jan 11 05:59:24 volumio volumio[8962]: info: Creating MPD Configuration file Jan 11 05:59:24 volumio sudo[9097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:24 volumio sudo[9097]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:24 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:24 volumio volumio[8962]: info: [1736571564590] CoreMusicLibrary::Adding element Last_100 Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:24 volumio volumio[8962]: info: [1736571564597] CoreMusicLibrary::Adding element Webradio Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:24 volumio sudo[9103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:24 volumio sudo[9101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:24 volumio sudo[9103]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:24 volumio volumio[8962]: info: Initializing BBC Radios Jan 11 05:59:24 volumio sudo[9101]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:24 volumio sudo[9101]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:24 volumio systemd[1]: mpd.service: Succeeded. Jan 11 05:59:24 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:24 volumio volumio[8962]: info: AutoStart - onStart Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:24 volumio volumio[8962]: info: [1736571564702] CoreMusicLibrary::Adding element LastFM Jan 11 05:59:24 volumio volumio[8962]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:24 volumio volumio[8962]: Cannot find translation for source LastFM Jan 11 05:59:24 volumio volumio[8962]: info: [LastFM] scrobbler initiated! Jan 11 05:59:24 volumio volumio[8962]: info: [LastFM] extended logging: false Jan 11 05:59:24 volumio volumio[8962]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 05:59:24 volumio volumio[8962]: info: [LastFM] Left init routine Jan 11 05:59:24 volumio volumio[8962]: info: [LastFM] Socket already connected: true Jan 11 05:59:24 volumio volumio[8962]: info: Volumio Calling Home Jan 11 05:59:24 volumio systemd[1]: Starting Music Player Daemon... Jan 11 05:59:24 volumio sudo[9113]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 05:59:24 volumio sudo[9113]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:24 volumio sudo[9113]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:24 volumio volumio[8962]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:24 volumio volumio[8962]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 05:59:24 volumio volumio[8962]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 05:59:24 volumio volumio[8962]: errno: -16, Jan 11 05:59:24 volumio volumio[8962]: code: 'EBUSY', Jan 11 05:59:24 volumio volumio[8962]: syscall: 'getaddrinfo', Jan 11 05:59:24 volumio volumio[8962]: hostname: 'ws.audioscrobbler.com' Jan 11 05:59:24 volumio volumio[8962]: } Jan 11 05:59:24 volumio volumio[8962]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:25 volumio sudo[9132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:58 Jan 11 05:59:25 volumio sudo[9132]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:25 volumio sudo[9132]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:25 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:25 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 05:59:25 volumio sudo[9103]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:25 volumio sudo[9097]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 05:59:25 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:25 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:25 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:25 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:26 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 05:59:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97476. Jan 11 05:59:26 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 05:59:26 volumio systemd[1]: Started Volumio Backend Module. Jan 11 05:59:26 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:26 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:26 volumio mpd[9122]: Jan 11 05:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 05:59:26 volumio systemd[1]: Started Music Player Daemon. Jan 11 05:59:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:27 volumio volumio[9145]: info: ------------------------------------------- Jan 11 05:59:27 volumio volumio[9145]: info: ----- Volumio3 ---- Jan 11 05:59:27 volumio volumio[9145]: info: ------------------------------------------- Jan 11 05:59:27 volumio volumio[9145]: info: ----- System startup ---- Jan 11 05:59:27 volumio volumio[9145]: info: ------------------------------------------- Jan 11 05:59:28 volumio volumio[9145]: info: MYVOLUMIO Environment detected Jan 11 05:59:28 volumio volumio[9145]: info: Plugin folders cleanup Jan 11 05:59:28 volumio volumio[9145]: info: Scanning into folder /volumio/app/plugins/ Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category audio_interface Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category miscellanea Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category music_service Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category plugins.json Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category system_controller Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category user_interface Jan 11 05:59:28 volumio volumio[9145]: info: Scanning into folder /data/plugins/ Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category system_controller Jan 11 05:59:28 volumio volumio[9145]: info: Scanning category user_interface Jan 11 05:59:28 volumio volumio[9145]: info: Plugin folders cleanup completed Jan 11 05:59:28 volumio volumio[9145]: info: ------------------------------------------- Jan 11 05:59:28 volumio volumio[9145]: info: ----- Core plugins startup ---- Jan 11 05:59:28 volumio volumio[9145]: info: ------------------------------------------- Jan 11 05:59:28 volumio volumio[9145]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 05:59:28 volumio volumio[9145]: info: Adding plugin upnp to MyMusic Plugins Jan 11 05:59:28 volumio volumio[9145]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 05:59:28 volumio volumio[9145]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 05:59:28 volumio volumio[9145]: info: Loading plugins from folder /data/plugins/ Jan 11 05:59:28 volumio volumio[9145]: info: Loading plugin "system"... Jan 11 05:59:28 volumio volumio[9145]: info: Loading plugin "appearance"... Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "network"... Jan 11 05:59:29 volumio volumio[9145]: info: Refreshing Cached IP Addresses Jan 11 05:59:29 volumio sudo[9174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 05:59:29 volumio sudo[9174]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:29 volumio sudo[9174]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:29 volumio sudo[9178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 05:59:29 volumio sudo[9178]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:29 volumio sudo[9178]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "services"... Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "alsa_controller"... Jan 11 05:59:29 volumio sudo[9191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 05:59:29 volumio sudo[9191]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:29 volumio sudo[9191]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:29 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "wizard"... Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "networkfs"... Jan 11 05:59:29 volumio volumio[9145]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 05:59:29 volumio volumio[9145]: info: Starting Udev Watcher for removable devices Jan 11 05:59:29 volumio volumio[9145]: info: Ignoring mount for partition: boot Jan 11 05:59:29 volumio volumio[9145]: info: Ignoring mount for partition: volumio Jan 11 05:59:29 volumio volumio[9145]: info: Ignoring mount for partition: volumio_data Jan 11 05:59:29 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "volumio_command_line_client"... Jan 11 05:59:29 volumio volumio[9145]: info: Plugin upnp is not enabled Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "my_music"... Jan 11 05:59:29 volumio volumio[9145]: info: Loading plugin "mpd"... Jan 11 05:59:30 volumio volumio[9145]: info: Plugin upnp_browser is not enabled Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "alarm-clock"... Jan 11 05:59:30 volumio volumio[9145]: info: Plugin airplay_emulation is not enabled Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "last_100"... Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "webradio"... Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "i2s_dacs"... Jan 11 05:59:30 volumio volumio[9145]: info: I2S DAC not set, start Auto-detection Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "volumiodiscovery"... Jan 11 05:59:30 volumio volumio[9145]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:30 volumio volumio[9145]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:30 volumio volumio[9145]: *** WARNING *** For more information see Jan 11 05:59:30 volumio node[9145]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:30 volumio volumio[9145]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:30 volumio volumio[9145]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:30 volumio volumio[9145]: *** WARNING *** For more information see Jan 11 05:59:30 volumio node[9145]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:30 volumio node[9145]: *** WARNING *** For more information see Jan 11 05:59:30 volumio node[9145]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:30 volumio node[9145]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:30 volumio node[9145]: *** WARNING *** For more information see Jan 11 05:59:30 volumio volumio[9145]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 05:59:30 volumio volumio[9145]: info: Discovery: Started advertising with name: Volumio Jan 11 05:59:30 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "autostart"... Jan 11 05:59:30 volumio volumio-remote-updater[569]: [2025-01-11 05:59:30] [connect] Successful connection Jan 11 05:59:30 volumio volumio[9145]: info: Applying required configuration parameters for plugin autostart Jan 11 05:59:30 volumio volumio[9145]: info: AutoStart - onVolumioStart - read config.json Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "outputs"... Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "albumart"... Jan 11 05:59:30 volumio volumio[9145]: info: Plugin example_plugin is not enabled Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "inputs"... Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "updater_comm"... Jan 11 05:59:30 volumio volumio[9145]: info: Plugin mpdemulation is not enabled Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "rest_api"... Jan 11 05:59:30 volumio volumio[9145]: info: Loading plugin "websocket"... Jan 11 05:59:31 volumio volumio[9145]: info: Starting Socket.io Server version 2.3.0 Jan 11 05:59:31 volumio volumio[9145]: info: Loading plugin "backup_restore"... Jan 11 05:59:31 volumio volumio[9145]: Forking 3 albumart workers Jan 11 05:59:31 volumio volumio[9145]: info: Applying required configuration parameters for plugin backup_restore Jan 11 05:59:31 volumio volumio[9145]: info: Loading plugin "Systeminfo"... Jan 11 05:59:31 volumio volumio[9145]: info: Loading plugin "lastfm"... Jan 11 05:59:31 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:32 volumio volumio[9145]: Starting albumart workers Jan 11 05:59:32 volumio volumio[9145]: Starting albumart workers Jan 11 05:59:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:32 volumio volumio[9145]: Starting albumart workers Jan 11 05:59:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:32 volumio volumio[9145]: info: Loading plugin "randomizer"... Jan 11 05:59:33 volumio volumio[9145]: info: Applying required configuration parameters for plugin randomizer Jan 11 05:59:33 volumio volumio[9145]: info: Loading i18n strings for locale en Jan 11 05:59:33 volumio volumio[9145]: Updating browse sources language Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::initPlayerControls Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: Express server listening on port 3000 Jan 11 05:59:33 volumio volumio[9145]: [Metrics] WebUI: 5s 864.18ms Jan 11 05:59:33 volumio volumio[9145]: info: CoreStateMachine::resetVolumioState Jan 11 05:59:33 volumio volumio[9145]: info: CoreStateMachine::getcurrentVolume Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:33 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:33 volumio volumio[9145]: info: Volumio Network Manager: Network status updated: 0 Jan 11 05:59:33 volumio volumio[9145]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 05:59:33 volumio volumio[9145]: wlan0 Interface doesn't support scanning : Device or resource busy Jan 11 05:59:33 volumio volumio[9145]: info: Cannot use regular scanning, forcing with ap-force Jan 11 05:59:33 volumio sudo[9266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 05:59:33 volumio sudo[9266]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:34 volumio wpa_supplicant[847]: wlan0: Failed to initiate sched scan Jan 11 05:59:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:34 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 05:59:36 volumio sudo[9266]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:36 volumio volumio[9145]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Jan 11 05:59:36 volumio volumio[9145]: info: CoreStateMachine::pushState Jan 11 05:59:36 volumio volumio[9145]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:36 volumio volumio[9145]: info: CoreStateMachine::updateTrackBlock Jan 11 05:59:36 volumio volumio[9145]: info: CorePlayQueue::getTrackBlock Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:36 volumio volumio[9145]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 11 05:59:36 volumio volumio[9145]: info: CoreStateMachine::pushState Jan 11 05:59:36 volumio volumio[9145]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:36 volumio volumio[9145]: info: CoreStateMachine::setRepeat true single undefined Jan 11 05:59:36 volumio volumio[9145]: info: CoreStateMachine::pushState Jan 11 05:59:36 volumio volumio[9145]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:36 volumio volumio[9145]: info: CoreStateMachine::setRandom true Jan 11 05:59:36 volumio volumio[9145]: info: CoreStateMachine::pushState Jan 11 05:59:36 volumio volumio[9145]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:36 volumio volumio[9145]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:36 volumio volumio[9145]: info: Setting Device type: Raspberry PI Jan 11 05:59:37 volumio volumio[9145]: info: Completed loading Core Plugins Jan 11 05:59:37 volumio volumio[9145]: info: Preparing to generate the ALSA configuration file Jan 11 05:59:37 volumio volumio[9145]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 05:59:37 volumio volumio[9145]: info: Reading ALSA contributions from plugins. Jan 11 05:59:37 volumio volumio[9145]: info: Asound.conf file unchanged, so no further update is needed Jan 11 05:59:37 volumio volumio[9145]: info: Output device has changed, restarting MPD Jan 11 05:59:37 volumio sudo[9279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:37 volumio sudo[9279]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:37 volumio volumio[9145]: info: ___________ START PLUGINS ___________ Jan 11 05:59:37 volumio sudo[9279]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:37 volumio volumio[9145]: info: ControllerMpd::onStart: Initializing MPD Jan 11 05:59:37 volumio volumio[9145]: info: Creating MPD Configuration file Jan 11 05:59:37 volumio sudo[9281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:37 volumio sudo[9281]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:37 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 05:59:37 volumio sudo[9285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:37 volumio sudo[9285]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:37 volumio sudo[9285]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:37 volumio volumio[9145]: info: [1736571577158] CoreMusicLibrary::Adding element Last_100 Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:37 volumio volumio[9145]: info: [1736571577166] CoreMusicLibrary::Adding element Webradio Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:37 volumio sudo[9288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:37 volumio sudo[9288]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:37 volumio volumio[9145]: info: Initializing BBC Radios Jan 11 05:59:37 volumio systemd[1]: mpd.service: Succeeded. Jan 11 05:59:37 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:37 volumio volumio[9145]: info: AutoStart - onStart Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:37 volumio volumio[9145]: info: [1736571577270] CoreMusicLibrary::Adding element LastFM Jan 11 05:59:37 volumio volumio[9145]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:37 volumio volumio[9145]: Cannot find translation for source LastFM Jan 11 05:59:37 volumio volumio[9145]: info: [LastFM] scrobbler initiated! Jan 11 05:59:37 volumio volumio[9145]: info: [LastFM] extended logging: false Jan 11 05:59:37 volumio volumio[9145]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 05:59:37 volumio volumio[9145]: info: [LastFM] Left init routine Jan 11 05:59:37 volumio volumio[9145]: info: [LastFM] Socket already connected: true Jan 11 05:59:37 volumio volumio[9145]: info: Volumio Calling Home Jan 11 05:59:37 volumio systemd[1]: Starting Music Player Daemon... Jan 11 05:59:37 volumio sudo[9296]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 05:59:37 volumio sudo[9296]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:37 volumio sudo[9296]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:37 volumio volumio[9145]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:37 volumio volumio[9145]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 05:59:37 volumio volumio[9145]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 05:59:37 volumio volumio[9145]: errno: -16, Jan 11 05:59:37 volumio volumio[9145]: code: 'EBUSY', Jan 11 05:59:37 volumio volumio[9145]: syscall: 'getaddrinfo', Jan 11 05:59:37 volumio volumio[9145]: hostname: 'ws.audioscrobbler.com' Jan 11 05:59:37 volumio volumio[9145]: } Jan 11 05:59:37 volumio volumio[9145]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:38 volumio sudo[9315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:58 Jan 11 05:59:38 volumio sudo[9315]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:38 volumio sudo[9315]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:38 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 05:59:38 volumio sudo[9288]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:38 volumio sudo[9281]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:38 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 05:59:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:38 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:38 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:38 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 05:59:38 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97477. Jan 11 05:59:38 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:38 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 05:59:38 volumio systemd[1]: Started Volumio Backend Module. Jan 11 05:59:38 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:38 volumio mpd[9305]: Jan 11 05:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 05:59:39 volumio systemd[1]: Started Music Player Daemon. Jan 11 05:59:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:40 volumio volumio[9329]: info: ------------------------------------------- Jan 11 05:59:40 volumio volumio[9329]: info: ----- Volumio3 ---- Jan 11 05:59:40 volumio volumio[9329]: info: ------------------------------------------- Jan 11 05:59:40 volumio volumio[9329]: info: ----- System startup ---- Jan 11 05:59:40 volumio volumio[9329]: info: ------------------------------------------- Jan 11 05:59:41 volumio volumio[9329]: info: MYVOLUMIO Environment detected Jan 11 05:59:41 volumio volumio[9329]: info: Plugin folders cleanup Jan 11 05:59:41 volumio volumio[9329]: info: Scanning into folder /volumio/app/plugins/ Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category audio_interface Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category miscellanea Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category music_service Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category plugins.json Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category system_controller Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category user_interface Jan 11 05:59:41 volumio volumio[9329]: info: Scanning into folder /data/plugins/ Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category system_controller Jan 11 05:59:41 volumio volumio[9329]: info: Scanning category user_interface Jan 11 05:59:41 volumio volumio[9329]: info: Plugin folders cleanup completed Jan 11 05:59:41 volumio volumio[9329]: info: ------------------------------------------- Jan 11 05:59:41 volumio volumio[9329]: info: ----- Core plugins startup ---- Jan 11 05:59:41 volumio volumio[9329]: info: ------------------------------------------- Jan 11 05:59:41 volumio volumio[9329]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 05:59:41 volumio volumio[9329]: info: Adding plugin upnp to MyMusic Plugins Jan 11 05:59:41 volumio volumio[9329]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 05:59:41 volumio volumio[9329]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 05:59:41 volumio volumio[9329]: info: Loading plugins from folder /data/plugins/ Jan 11 05:59:41 volumio volumio[9329]: info: Loading plugin "system"... Jan 11 05:59:41 volumio volumio[9329]: info: Loading plugin "appearance"... Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "network"... Jan 11 05:59:42 volumio volumio[9329]: info: Refreshing Cached IP Addresses Jan 11 05:59:42 volumio sudo[9360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 05:59:42 volumio sudo[9360]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:42 volumio sudo[9362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 05:59:42 volumio sudo[9360]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:42 volumio sudo[9362]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:42 volumio sudo[9362]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "services"... Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "alsa_controller"... Jan 11 05:59:42 volumio sudo[9375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 05:59:42 volumio sudo[9375]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:42 volumio sudo[9375]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:42 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "wizard"... Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "networkfs"... Jan 11 05:59:42 volumio volumio[9329]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 05:59:42 volumio volumio[9329]: info: Starting Udev Watcher for removable devices Jan 11 05:59:42 volumio volumio[9329]: info: Ignoring mount for partition: boot Jan 11 05:59:42 volumio volumio[9329]: info: Ignoring mount for partition: volumio Jan 11 05:59:42 volumio volumio[9329]: info: Ignoring mount for partition: volumio_data Jan 11 05:59:42 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "volumio_command_line_client"... Jan 11 05:59:42 volumio volumio[9329]: info: Plugin upnp is not enabled Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "my_music"... Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "mpd"... Jan 11 05:59:42 volumio volumio[9329]: info: Plugin upnp_browser is not enabled Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "alarm-clock"... Jan 11 05:59:42 volumio volumio[9329]: info: Plugin airplay_emulation is not enabled Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "last_100"... Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "webradio"... Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "i2s_dacs"... Jan 11 05:59:42 volumio volumio[9329]: info: I2S DAC not set, start Auto-detection Jan 11 05:59:42 volumio volumio[9329]: info: Loading plugin "volumiodiscovery"... Jan 11 05:59:42 volumio volumio[9329]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:42 volumio volumio[9329]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:42 volumio volumio[9329]: *** WARNING *** For more information see Jan 11 05:59:42 volumio node[9329]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:42 volumio volumio[9329]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:42 volumio volumio[9329]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:42 volumio volumio[9329]: *** WARNING *** For more information see Jan 11 05:59:42 volumio node[9329]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:42 volumio node[9329]: *** WARNING *** For more information see Jan 11 05:59:42 volumio node[9329]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:42 volumio node[9329]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:42 volumio node[9329]: *** WARNING *** For more information see Jan 11 05:59:42 volumio volumio[9329]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 05:59:42 volumio volumio[9329]: info: Discovery: Started advertising with name: Volumio Jan 11 05:59:43 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "autostart"... Jan 11 05:59:43 volumio volumio[9329]: info: Applying required configuration parameters for plugin autostart Jan 11 05:59:43 volumio volumio[9329]: info: AutoStart - onVolumioStart - read config.json Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "outputs"... Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "albumart"... Jan 11 05:59:43 volumio volumio[9329]: info: Plugin example_plugin is not enabled Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "inputs"... Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "updater_comm"... Jan 11 05:59:43 volumio volumio[9329]: info: Plugin mpdemulation is not enabled Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "rest_api"... Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "websocket"... Jan 11 05:59:43 volumio volumio[9329]: info: Starting Socket.io Server version 2.3.0 Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "backup_restore"... Jan 11 05:59:43 volumio volumio[9329]: Forking 3 albumart workers Jan 11 05:59:43 volumio volumio[9329]: info: Applying required configuration parameters for plugin backup_restore Jan 11 05:59:43 volumio volumio[9329]: info: Loading plugin "Systeminfo"... Jan 11 05:59:44 volumio volumio[9329]: info: Loading plugin "lastfm"... Jan 11 05:59:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:44 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 05:59:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:44 volumio volumio[9329]: Starting albumart workers Jan 11 05:59:44 volumio volumio[9329]: Starting albumart workers Jan 11 05:59:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:44 volumio volumio[9329]: Starting albumart workers Jan 11 05:59:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:44 volumio volumio[9329]: info: Loading plugin "randomizer"... Jan 11 05:59:45 volumio volumio[9329]: info: Applying required configuration parameters for plugin randomizer Jan 11 05:59:45 volumio volumio[9329]: info: Loading i18n strings for locale en Jan 11 05:59:45 volumio volumio[9329]: Updating browse sources language Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::initPlayerControls Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: Express server listening on port 3000 Jan 11 05:59:45 volumio volumio[9329]: [Metrics] WebUI: 5s 823.61ms Jan 11 05:59:45 volumio volumio-remote-updater[569]: [2025-01-11 05:59:45] [connect] Successful connection Jan 11 05:59:45 volumio volumio[9329]: info: CoreStateMachine::resetVolumioState Jan 11 05:59:45 volumio volumio[9329]: info: CoreStateMachine::getcurrentVolume Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:45 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:45 volumio volumio[9329]: info: Volumio Network Manager: Network status updated: 0 Jan 11 05:59:45 volumio volumio[9329]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 05:59:45 volumio volumio[9329]: wlan0 Interface doesn't support scanning : Device or resource busy Jan 11 05:59:45 volumio volumio[9329]: info: Cannot use regular scanning, forcing with ap-force Jan 11 05:59:45 volumio sudo[9449]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 05:59:45 volumio sudo[9449]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:46 volumio wpa_supplicant[847]: wlan0: Failed to initiate sched scan Jan 11 05:59:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:49 volumio sudo[9449]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:49 volumio volumio[9329]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Jan 11 05:59:49 volumio volumio-remote-updater[569]: [2025-01-11 05:59:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736571585 101 Jan 11 05:59:49 volumio volumio[9329]: 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 Jan 11 05:59:49 volumio volumio[9329]: info: CoreStateMachine::pushState Jan 11 05:59:49 volumio volumio[9329]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:49 volumio volumio[9329]: info: CoreStateMachine::updateTrackBlock Jan 11 05:59:49 volumio volumio[9329]: info: CorePlayQueue::getTrackBlock Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:49 volumio volumio[9329]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 05:59:49 volumio volumio[9329]: info: CoreStateMachine::pushState Jan 11 05:59:49 volumio volumio[9329]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:49 volumio volumio[9329]: info: CoreStateMachine::setRepeat true single undefined Jan 11 05:59:49 volumio volumio[9329]: info: CoreStateMachine::pushState Jan 11 05:59:49 volumio volumio[9329]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:49 volumio volumio[9329]: info: CoreStateMachine::setRandom true Jan 11 05:59:49 volumio volumio[9329]: info: CoreStateMachine::pushState Jan 11 05:59:49 volumio volumio[9329]: info: CorePlayQueue::getTrack 0 Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioPushState Jan 11 05:59:49 volumio volumio[9329]: info: Setting Device type: Raspberry PI Jan 11 05:59:49 volumio volumio[9329]: info: Completed loading Core Plugins Jan 11 05:59:49 volumio volumio[9329]: info: Preparing to generate the ALSA configuration file Jan 11 05:59:49 volumio volumio[9329]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 05:59:49 volumio volumio[9329]: info: Reading ALSA contributions from plugins. Jan 11 05:59:49 volumio volumio[9329]: info: Asound.conf file unchanged, so no further update is needed Jan 11 05:59:49 volumio volumio[9329]: info: Output device has changed, restarting MPD Jan 11 05:59:49 volumio sudo[9462]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:49 volumio sudo[9462]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:49 volumio volumio[9329]: info: ___________ START PLUGINS ___________ Jan 11 05:59:49 volumio sudo[9462]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:49 volumio volumio[9329]: info: ControllerMpd::onStart: Initializing MPD Jan 11 05:59:49 volumio volumio[9329]: info: Creating MPD Configuration file Jan 11 05:59:49 volumio sudo[9464]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:49 volumio sudo[9464]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:49 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 05:59:49 volumio sudo[9468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:49 volumio volumio[9329]: info: [1736571589668] CoreMusicLibrary::Adding element Last_100 Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:49 volumio sudo[9468]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:49 volumio sudo[9468]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:49 volumio volumio[9329]: info: [1736571589684] CoreMusicLibrary::Adding element Webradio Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:49 volumio sudo[9472]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 05:59:49 volumio sudo[9472]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:49 volumio volumio[9329]: info: Initializing BBC Radios Jan 11 05:59:49 volumio systemd[1]: mpd.service: Succeeded. Jan 11 05:59:49 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:49 volumio volumio[9329]: info: AutoStart - onStart Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 05:59:49 volumio volumio[9329]: info: [1736571589789] CoreMusicLibrary::Adding element LastFM Jan 11 05:59:49 volumio volumio[9329]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:49 volumio volumio[9329]: Cannot find translation for source LastFM Jan 11 05:59:49 volumio volumio[9329]: info: [LastFM] scrobbler initiated! Jan 11 05:59:49 volumio volumio[9329]: info: [LastFM] extended logging: false Jan 11 05:59:49 volumio volumio[9329]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 05:59:49 volumio volumio[9329]: info: [LastFM] Left init routine Jan 11 05:59:49 volumio volumio[9329]: info: [LastFM] Socket already connected: true Jan 11 05:59:49 volumio systemd[1]: Starting Music Player Daemon... Jan 11 05:59:49 volumio volumio[9329]: info: Volumio Calling Home Jan 11 05:59:49 volumio sudo[9481]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 05:59:49 volumio sudo[9481]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:49 volumio sudo[9481]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:50 volumio volumio[9329]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:50 volumio volumio[9329]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 05:59:50 volumio volumio[9329]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 05:59:50 volumio volumio[9329]: errno: -16, Jan 11 05:59:50 volumio volumio[9329]: code: 'EBUSY', Jan 11 05:59:50 volumio volumio[9329]: syscall: 'getaddrinfo', Jan 11 05:59:50 volumio volumio[9329]: hostname: 'ws.audioscrobbler.com' Jan 11 05:59:50 volumio volumio[9329]: } Jan 11 05:59:50 volumio volumio[9329]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 05:59:50 volumio sudo[9500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:58 Jan 11 05:59:50 volumio sudo[9500]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:50 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:50 volumio sudo[9500]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:50 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:50 volumio volumio-remote-updater[569]: [2025-01-11 05:59:50] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 05:59:50 volumio volumio-remote-updater[569]: [2025-01-11 05:59:50] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 05:59:50 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 05:59:50 volumio sudo[9472]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:50 volumio sudo[9464]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:50 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 05:59:50 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:50 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:50 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:51 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:51 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 05:59:51 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97478. Jan 11 05:59:51 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 05:59:51 volumio systemd[1]: Started Volumio Backend Module. Jan 11 05:59:51 volumio systemd[1]: Started dynamicswap service. Jan 11 05:59:51 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 05:59:51 volumio mpd[9490]: Jan 11 05:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 05:59:51 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 05:59:51 volumio systemd[1]: mpd.service: Failed with result 'protocol'. Jan 11 05:59:51 volumio systemd[1]: Failed to start Music Player Daemon. Jan 11 05:59:51 volumio systemd[1]: Starting Music Player Daemon... Jan 11 05:59:51 volumio sudo[9528]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 05:59:51 volumio sudo[9528]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:51 volumio sudo[9528]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 05:59:52 volumio volumio[9513]: info: ------------------------------------------- Jan 11 05:59:52 volumio volumio[9513]: info: ----- Volumio3 ---- Jan 11 05:59:52 volumio volumio[9513]: info: ------------------------------------------- Jan 11 05:59:52 volumio volumio[9513]: info: ----- System startup ---- Jan 11 05:59:53 volumio volumio[9513]: info: ------------------------------------------- Jan 11 05:59:53 volumio mpd[9530]: Jan 11 05:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 05:59:53 volumio volumio[9513]: info: MYVOLUMIO Environment detected Jan 11 05:59:53 volumio volumio[9513]: info: Plugin folders cleanup Jan 11 05:59:53 volumio volumio[9513]: info: Scanning into folder /volumio/app/plugins/ Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category audio_interface Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category miscellanea Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category music_service Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category plugins.json Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category system_controller Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category user_interface Jan 11 05:59:53 volumio volumio[9513]: info: Scanning into folder /data/plugins/ Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category system_controller Jan 11 05:59:53 volumio volumio[9513]: info: Scanning category user_interface Jan 11 05:59:53 volumio volumio[9513]: info: Plugin folders cleanup completed Jan 11 05:59:53 volumio volumio[9513]: info: ------------------------------------------- Jan 11 05:59:53 volumio volumio[9513]: info: ----- Core plugins startup ---- Jan 11 05:59:53 volumio volumio[9513]: info: ------------------------------------------- Jan 11 05:59:53 volumio volumio[9513]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 05:59:53 volumio volumio[9513]: info: Adding plugin upnp to MyMusic Plugins Jan 11 05:59:53 volumio volumio[9513]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 05:59:53 volumio volumio[9513]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 05:59:53 volumio volumio[9513]: info: Loading plugins from folder /data/plugins/ Jan 11 05:59:53 volumio systemd[1]: Started Music Player Daemon. Jan 11 05:59:53 volumio mpd_monitor.sh[572]: MPD restarted due to no mpc output. Jan 11 05:59:53 volumio volumio[9513]: info: Loading plugin "system"... Jan 11 05:59:53 volumio ntpd[727]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jan 11 05:59:53 volumio volumio[9513]: info: Loading plugin "appearance"... Jan 11 05:59:54 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 05:59:54 volumio volumio[9513]: info: Loading plugin "network"... Jan 11 05:59:54 volumio volumio[9513]: info: Refreshing Cached IP Addresses Jan 11 05:59:54 volumio sudo[9548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 05:59:54 volumio sudo[9548]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:54 volumio sudo[9548]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:54 volumio sudo[9550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 05:59:54 volumio sudo[9550]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:54 volumio sudo[9550]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:54 volumio volumio[9513]: info: Loading plugin "services"... Jan 11 05:59:54 volumio volumio[9513]: info: Loading plugin "alsa_controller"... Jan 11 05:59:54 volumio sudo[9559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 05:59:54 volumio sudo[9559]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:54 volumio sudo[9559]: pam_unix(sudo:session): session closed for user root Jan 11 05:59:54 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 05:59:54 volumio volumio[9513]: info: Loading plugin "wizard"... Jan 11 05:59:54 volumio volumio[9513]: info: Loading plugin "networkfs"... Jan 11 05:59:55 volumio volumio[9513]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 05:59:55 volumio volumio[9513]: info: Starting Udev Watcher for removable devices Jan 11 05:59:55 volumio volumio[9513]: info: Ignoring mount for partition: boot Jan 11 05:59:55 volumio volumio[9513]: info: Ignoring mount for partition: volumio Jan 11 05:59:55 volumio volumio[9513]: info: Ignoring mount for partition: volumio_data Jan 11 05:59:55 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "volumio_command_line_client"... Jan 11 05:59:55 volumio volumio[9513]: info: Plugin upnp is not enabled Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "my_music"... Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "mpd"... Jan 11 05:59:55 volumio volumio[9513]: info: Plugin upnp_browser is not enabled Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "alarm-clock"... Jan 11 05:59:55 volumio volumio[9513]: info: Plugin airplay_emulation is not enabled Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "last_100"... Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "webradio"... Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "i2s_dacs"... Jan 11 05:59:55 volumio volumio[9513]: info: I2S DAC not set, start Auto-detection Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "volumiodiscovery"... Jan 11 05:59:55 volumio volumio[9513]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:55 volumio volumio[9513]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:55 volumio volumio[9513]: *** WARNING *** For more information see Jan 11 05:59:55 volumio node[9513]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:55 volumio volumio[9513]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:55 volumio volumio[9513]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:55 volumio volumio[9513]: *** WARNING *** For more information see Jan 11 05:59:55 volumio node[9513]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:55 volumio node[9513]: *** WARNING *** For more information see Jan 11 05:59:55 volumio node[9513]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 05:59:55 volumio node[9513]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 05:59:55 volumio node[9513]: *** WARNING *** For more information see Jan 11 05:59:55 volumio volumio[9513]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 05:59:55 volumio volumio[9513]: info: Discovery: Started advertising with name: Volumio Jan 11 05:59:55 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "autostart"... Jan 11 05:59:55 volumio volumio-remote-updater[569]: [2025-01-11 05:59:55] [connect] Successful connection Jan 11 05:59:55 volumio volumio[9513]: info: Applying required configuration parameters for plugin autostart Jan 11 05:59:55 volumio volumio[9513]: info: AutoStart - onVolumioStart - read config.json Jan 11 05:59:55 volumio volumio[9513]: info: Loading plugin "outputs"... Jan 11 05:59:56 volumio volumio[9513]: info: Loading plugin "albumart"... Jan 11 05:59:56 volumio volumio[9513]: info: Plugin example_plugin is not enabled Jan 11 05:59:56 volumio volumio[9513]: info: Loading plugin "inputs"... Jan 11 05:59:56 volumio volumio[9513]: info: Loading plugin "updater_comm"... Jan 11 05:59:56 volumio volumio[9513]: info: Plugin mpdemulation is not enabled Jan 11 05:59:56 volumio volumio[9513]: info: Loading plugin "rest_api"... Jan 11 05:59:56 volumio volumio[9513]: info: Loading plugin "websocket"... Jan 11 05:59:56 volumio volumio[9513]: info: Starting Socket.io Server version 2.3.0 Jan 11 05:59:56 volumio volumio[9513]: info: Loading plugin "backup_restore"... Jan 11 05:59:56 volumio volumio[9513]: Forking 3 albumart workers Jan 11 05:59:56 volumio volumio[9513]: info: Applying required configuration parameters for plugin backup_restore Jan 11 05:59:56 volumio volumio[9513]: info: Loading plugin "Systeminfo"... Jan 11 05:59:57 volumio volumio[9513]: info: Loading plugin "lastfm"... Jan 11 05:59:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 05:59:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 05:59:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 05:59:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 05:59:57 volumio volumio[9513]: Starting albumart workers Jan 11 05:59:57 volumio volumio[9513]: Starting albumart workers Jan 11 05:59:57 volumio volumio[9513]: Starting albumart workers Jan 11 05:59:57 volumio volumio[9513]: info: Loading plugin "randomizer"... Jan 11 05:59:58 volumio volumio[9513]: info: Applying required configuration parameters for plugin randomizer Jan 11 05:59:58 volumio volumio[9513]: info: Loading i18n strings for locale en Jan 11 05:59:58 volumio volumio[9513]: Updating browse sources language Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::initPlayerControls Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: Express server listening on port 3000 Jan 11 05:59:58 volumio volumio[9513]: [Metrics] WebUI: 6s 21.82ms Jan 11 05:59:58 volumio volumio[9513]: info: CoreStateMachine::resetVolumioState Jan 11 05:59:58 volumio volumio[9513]: info: CoreStateMachine::getcurrentVolume Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 05:59:58 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 05:59:58 volumio volumio[9513]: info: Volumio Network Manager: Network status updated: 0 Jan 11 05:59:58 volumio volumio[9513]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 05:59:58 volumio volumio[9513]: wlan0 Interface doesn't support scanning : Device or resource busy Jan 11 05:59:58 volumio volumio[9513]: info: Cannot use regular scanning, forcing with ap-force Jan 11 05:59:58 volumio sudo[9637]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 05:59:58 volumio sudo[9637]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 05:59:59 volumio wpa_supplicant[847]: wlan0: Failed to initiate sched scan Jan 11 05:59:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 05:59:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 05:59:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 05:59:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 05:59:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 05:59:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 06:00:00 volumio ntpd[727]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jan 11 06:00:01 volumio sudo[9637]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:01 volumio volumio[9513]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Jan 11 06:00:01 volumio volumio[9513]: info: CoreStateMachine::pushState Jan 11 06:00:01 volumio volumio[9513]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:01 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:01 volumio volumio[9513]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:01 volumio volumio[9513]: info: CoreStateMachine::updateTrackBlock Jan 11 06:00:01 volumio volumio[9513]: info: CorePlayQueue::getTrackBlock Jan 11 06:00:01 volumio volumio[9513]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:00:01 volumio volumio[9513]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 11 06:00:02 volumio volumio[9513]: info: CoreStateMachine::pushState Jan 11 06:00:02 volumio volumio[9513]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:02 volumio volumio[9513]: info: CoreStateMachine::setRepeat true single undefined Jan 11 06:00:02 volumio volumio[9513]: info: CoreStateMachine::pushState Jan 11 06:00:02 volumio volumio[9513]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:02 volumio volumio[9513]: info: CoreStateMachine::setRandom true Jan 11 06:00:02 volumio volumio[9513]: info: CoreStateMachine::pushState Jan 11 06:00:02 volumio volumio[9513]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:02 volumio volumio[9513]: info: Setting Device type: Raspberry PI Jan 11 06:00:02 volumio volumio[9513]: info: Completed loading Core Plugins Jan 11 06:00:02 volumio volumio[9513]: info: Preparing to generate the ALSA configuration file Jan 11 06:00:02 volumio volumio[9513]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 06:00:02 volumio volumio[9513]: info: Reading ALSA contributions from plugins. Jan 11 06:00:02 volumio volumio[9513]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:00:02 volumio volumio[9513]: info: Output device has changed, restarting MPD Jan 11 06:00:02 volumio sudo[9650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:02 volumio sudo[9650]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:02 volumio volumio[9513]: info: ___________ START PLUGINS ___________ Jan 11 06:00:02 volumio sudo[9650]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:02 volumio volumio[9513]: info: ControllerMpd::onStart: Initializing MPD Jan 11 06:00:02 volumio volumio[9513]: info: Creating MPD Configuration file Jan 11 06:00:02 volumio sudo[9653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:02 volumio sudo[9653]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:02 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 06:00:02 volumio sudo[9656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:02 volumio sudo[9656]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:02 volumio sudo[9656]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:02 volumio sudo[9658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:02 volumio sudo[9658]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:02 volumio volumio[9513]: info: [1736571602296] CoreMusicLibrary::Adding element Last_100 Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:02 volumio volumio[9513]: info: [1736571602303] CoreMusicLibrary::Adding element Webradio Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:02 volumio volumio[9513]: info: Initializing BBC Radios Jan 11 06:00:02 volumio systemd[1]: mpd.service: Succeeded. Jan 11 06:00:02 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:00:02 volumio volumio[9513]: info: AutoStart - onStart Jan 11 06:00:02 volumio systemd[1]: Starting Music Player Daemon... Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:02 volumio volumio[9513]: info: [1736571602401] CoreMusicLibrary::Adding element LastFM Jan 11 06:00:02 volumio volumio[9513]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:02 volumio volumio[9513]: Cannot find translation for source LastFM Jan 11 06:00:02 volumio volumio[9513]: info: [LastFM] scrobbler initiated! Jan 11 06:00:02 volumio volumio[9513]: info: [LastFM] extended logging: false Jan 11 06:00:02 volumio volumio[9513]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 06:00:02 volumio volumio[9513]: info: [LastFM] Left init routine Jan 11 06:00:02 volumio volumio[9513]: info: [LastFM] Socket already connected: true Jan 11 06:00:02 volumio volumio[9513]: info: Volumio Calling Home Jan 11 06:00:02 volumio sudo[9662]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:00:02 volumio sudo[9662]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:02 volumio sudo[9662]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:02 volumio volumio[9513]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:02 volumio volumio[9513]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 06:00:02 volumio volumio[9513]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 06:00:02 volumio volumio[9513]: errno: -16, Jan 11 06:00:02 volumio volumio[9513]: code: 'EBUSY', Jan 11 06:00:02 volumio volumio[9513]: syscall: 'getaddrinfo', Jan 11 06:00:02 volumio volumio[9513]: hostname: 'ws.audioscrobbler.com' Jan 11 06:00:02 volumio volumio[9513]: } Jan 11 06:00:02 volumio volumio[9513]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:03 volumio sudo[9686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:59 Jan 11 06:00:03 volumio sudo[9686]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 06:00:03 volumio sudo[9686]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 06:00:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:00:03 volumio sudo[9653]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:03 volumio sudo[9658]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 06:00:03 volumio systemd[1]: Started dynamicswap service. Jan 11 06:00:03 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 06:00:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 06:00:03 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 06:00:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97479. Jan 11 06:00:03 volumio systemd[1]: Started dynamicswap service. Jan 11 06:00:03 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 06:00:03 volumio systemd[1]: Started Volumio Backend Module. Jan 11 06:00:03 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 06:00:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 06:00:03 volumio ntpd[727]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jan 11 06:00:03 volumio mpd[9676]: Jan 11 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 06:00:04 volumio systemd[1]: Started Music Player Daemon. Jan 11 06:00:04 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 06:00:05 volumio volumio[9701]: info: ------------------------------------------- Jan 11 06:00:05 volumio volumio[9701]: info: ----- Volumio3 ---- Jan 11 06:00:05 volumio volumio[9701]: info: ------------------------------------------- Jan 11 06:00:05 volumio volumio[9701]: info: ----- System startup ---- Jan 11 06:00:05 volumio volumio[9701]: info: ------------------------------------------- Jan 11 06:00:05 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 06:00:05 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 06:00:05 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 06:00:05 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 06:00:05 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 06:00:05 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 06:00:06 volumio volumio[9701]: info: MYVOLUMIO Environment detected Jan 11 06:00:06 volumio volumio[9701]: info: Plugin folders cleanup Jan 11 06:00:06 volumio volumio[9701]: info: Scanning into folder /volumio/app/plugins/ Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category audio_interface Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category miscellanea Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category music_service Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category plugins.json Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category system_controller Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category user_interface Jan 11 06:00:06 volumio volumio[9701]: info: Scanning into folder /data/plugins/ Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category system_controller Jan 11 06:00:06 volumio volumio[9701]: info: Scanning category user_interface Jan 11 06:00:06 volumio volumio[9701]: info: Plugin folders cleanup completed Jan 11 06:00:06 volumio volumio[9701]: info: ------------------------------------------- Jan 11 06:00:06 volumio volumio[9701]: info: ----- Core plugins startup ---- Jan 11 06:00:06 volumio volumio[9701]: info: ------------------------------------------- Jan 11 06:00:06 volumio volumio[9701]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 06:00:06 volumio volumio[9701]: info: Adding plugin upnp to MyMusic Plugins Jan 11 06:00:06 volumio volumio[9701]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 06:00:06 volumio volumio[9701]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 06:00:06 volumio volumio[9701]: info: Loading plugins from folder /data/plugins/ Jan 11 06:00:06 volumio volumio[9701]: info: Loading plugin "system"... Jan 11 06:00:06 volumio volumio[9701]: info: Loading plugin "appearance"... Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "network"... Jan 11 06:00:07 volumio volumio[9701]: info: Refreshing Cached IP Addresses Jan 11 06:00:07 volumio sudo[9770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 06:00:07 volumio sudo[9770]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:07 volumio sudo[9770]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:07 volumio sudo[9772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 06:00:07 volumio sudo[9772]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:07 volumio sudo[9772]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "services"... Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "alsa_controller"... Jan 11 06:00:07 volumio sudo[9781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 06:00:07 volumio sudo[9781]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:07 volumio sudo[9781]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:07 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "wizard"... Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "networkfs"... Jan 11 06:00:07 volumio volumio[9701]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 06:00:07 volumio volumio[9701]: info: Starting Udev Watcher for removable devices Jan 11 06:00:07 volumio volumio[9701]: info: Ignoring mount for partition: boot Jan 11 06:00:07 volumio volumio[9701]: info: Ignoring mount for partition: volumio Jan 11 06:00:07 volumio volumio[9701]: info: Ignoring mount for partition: volumio_data Jan 11 06:00:07 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "volumio_command_line_client"... Jan 11 06:00:07 volumio volumio[9701]: info: Plugin upnp is not enabled Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "my_music"... Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "mpd"... Jan 11 06:00:07 volumio volumio[9701]: info: Plugin upnp_browser is not enabled Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "alarm-clock"... Jan 11 06:00:07 volumio volumio[9701]: info: Plugin airplay_emulation is not enabled Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "last_100"... Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "webradio"... Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "i2s_dacs"... Jan 11 06:00:07 volumio volumio[9701]: info: I2S DAC not set, start Auto-detection Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "volumiodiscovery"... Jan 11 06:00:07 volumio volumio[9701]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:07 volumio volumio[9701]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:07 volumio volumio[9701]: *** WARNING *** For more information see Jan 11 06:00:07 volumio volumio[9701]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:07 volumio node[9701]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:07 volumio volumio[9701]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:07 volumio volumio[9701]: *** WARNING *** For more information see Jan 11 06:00:07 volumio node[9701]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:07 volumio node[9701]: *** WARNING *** For more information see Jan 11 06:00:07 volumio node[9701]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:07 volumio node[9701]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:07 volumio node[9701]: *** WARNING *** For more information see Jan 11 06:00:07 volumio volumio[9701]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 06:00:07 volumio volumio[9701]: info: Discovery: Started advertising with name: Volumio Jan 11 06:00:07 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:00:07 volumio volumio[9701]: info: Loading plugin "autostart"... Jan 11 06:00:08 volumio volumio[9701]: info: Applying required configuration parameters for plugin autostart Jan 11 06:00:08 volumio volumio[9701]: info: AutoStart - onVolumioStart - read config.json Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "outputs"... Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "albumart"... Jan 11 06:00:08 volumio volumio[9701]: info: Plugin example_plugin is not enabled Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "inputs"... Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "updater_comm"... Jan 11 06:00:08 volumio volumio-remote-updater[569]: [2025-01-11 06:00:08] [connect] Successful connection Jan 11 06:00:08 volumio volumio[9701]: info: Plugin mpdemulation is not enabled Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "rest_api"... Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "websocket"... Jan 11 06:00:08 volumio volumio[9701]: info: Starting Socket.io Server version 2.3.0 Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "backup_restore"... Jan 11 06:00:08 volumio volumio[9701]: Forking 3 albumart workers Jan 11 06:00:08 volumio volumio[9701]: info: Applying required configuration parameters for plugin backup_restore Jan 11 06:00:08 volumio volumio[9701]: info: Loading plugin "Systeminfo"... Jan 11 06:00:09 volumio volumio[9701]: info: Loading plugin "lastfm"... Jan 11 06:00:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 06:00:09 volumio volumio[9701]: Starting albumart workers Jan 11 06:00:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 06:00:09 volumio volumio[9701]: Starting albumart workers Jan 11 06:00:09 volumio volumio[9701]: Starting albumart workers Jan 11 06:00:09 volumio volumio[9701]: info: Loading plugin "randomizer"... Jan 11 06:00:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 06:00:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 06:00:10 volumio volumio[9701]: info: Applying required configuration parameters for plugin randomizer Jan 11 06:00:10 volumio volumio[9701]: info: Loading i18n strings for locale en Jan 11 06:00:10 volumio volumio[9701]: Updating browse sources language Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::initPlayerControls Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: Express server listening on port 3000 Jan 11 06:00:10 volumio volumio[9701]: [Metrics] WebUI: 5s 759.06ms Jan 11 06:00:10 volumio volumio[9701]: info: CoreStateMachine::resetVolumioState Jan 11 06:00:10 volumio volumio[9701]: info: CoreStateMachine::getcurrentVolume Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:00:10 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:00:10 volumio volumio[9701]: info: Volumio Network Manager: Network status updated: 0 Jan 11 06:00:10 volumio volumio[9701]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 06:00:10 volumio volumio[9701]: wlan0 Interface doesn't support scanning : Device or resource busy Jan 11 06:00:10 volumio volumio[9701]: info: Cannot use regular scanning, forcing with ap-force Jan 11 06:00:10 volumio sudo[9859]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 06:00:10 volumio sudo[9859]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:11 volumio wpa_supplicant[847]: wlan0: Failed to initiate sched scan Jan 11 06:00:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 06:00:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 06:00:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 06:00:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 06:00:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 06:00:11 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 06:00:11 volumio ntpd[727]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 11 06:00:14 volumio sudo[9859]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:14 volumio volumio[9701]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Jan 11 06:00:14 volumio volumio[9701]: info: CoreStateMachine::pushState Jan 11 06:00:14 volumio volumio[9701]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:14 volumio volumio[9701]: info: CoreStateMachine::updateTrackBlock Jan 11 06:00:14 volumio volumio[9701]: info: CorePlayQueue::getTrackBlock Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:00:14 volumio volumio[9701]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 11 06:00:14 volumio volumio[9701]: info: CoreStateMachine::pushState Jan 11 06:00:14 volumio volumio[9701]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:14 volumio volumio[9701]: info: CoreStateMachine::setRepeat true single undefined Jan 11 06:00:14 volumio volumio[9701]: info: CoreStateMachine::pushState Jan 11 06:00:14 volumio volumio[9701]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:14 volumio volumio[9701]: info: CoreStateMachine::setRandom true Jan 11 06:00:14 volumio volumio[9701]: info: CoreStateMachine::pushState Jan 11 06:00:14 volumio volumio[9701]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:14 volumio volumio[9701]: info: Setting Device type: Raspberry PI Jan 11 06:00:14 volumio volumio[9701]: info: Completed loading Core Plugins Jan 11 06:00:14 volumio volumio[9701]: info: Preparing to generate the ALSA configuration file Jan 11 06:00:14 volumio volumio[9701]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 06:00:14 volumio volumio[9701]: info: Reading ALSA contributions from plugins. Jan 11 06:00:14 volumio volumio[9701]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:00:14 volumio volumio[9701]: info: Output device has changed, restarting MPD Jan 11 06:00:14 volumio sudo[9876]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:14 volumio sudo[9876]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:14 volumio volumio[9701]: info: ___________ START PLUGINS ___________ Jan 11 06:00:14 volumio sudo[9876]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:14 volumio volumio[9701]: info: ControllerMpd::onStart: Initializing MPD Jan 11 06:00:14 volumio volumio[9701]: info: Creating MPD Configuration file Jan 11 06:00:14 volumio sudo[9878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:14 volumio sudo[9878]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:14 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 06:00:14 volumio sudo[9882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:14 volumio sudo[9882]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:14 volumio sudo[9882]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:14 volumio volumio[9701]: info: [1736571614826] CoreMusicLibrary::Adding element Last_100 Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:14 volumio sudo[9885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:14 volumio sudo[9885]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:14 volumio volumio[9701]: info: [1736571614832] CoreMusicLibrary::Adding element Webradio Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:14 volumio volumio[9701]: info: Initializing BBC Radios Jan 11 06:00:14 volumio systemd[1]: mpd.service: Succeeded. Jan 11 06:00:14 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 06:00:14 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:00:14 volumio volumio[9701]: info: AutoStart - onStart Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:14 volumio volumio[9701]: info: [1736571614947] CoreMusicLibrary::Adding element LastFM Jan 11 06:00:14 volumio volumio[9701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:14 volumio volumio[9701]: Cannot find translation for source LastFM Jan 11 06:00:14 volumio volumio[9701]: info: [LastFM] scrobbler initiated! Jan 11 06:00:14 volumio volumio[9701]: info: [LastFM] extended logging: false Jan 11 06:00:14 volumio volumio[9701]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 06:00:14 volumio systemd[1]: Starting Music Player Daemon... Jan 11 06:00:14 volumio volumio[9701]: info: [LastFM] Left init routine Jan 11 06:00:14 volumio volumio[9701]: info: [LastFM] Socket already connected: true Jan 11 06:00:14 volumio volumio[9701]: info: Volumio Calling Home Jan 11 06:00:15 volumio sudo[9889]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:00:15 volumio sudo[9889]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:15 volumio sudo[9889]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:15 volumio volumio[9701]: info: Reloading queue from file Jan 11 06:00:15 volumio volumio[9701]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:15 volumio volumio[9701]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 06:00:15 volumio volumio[9701]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 06:00:15 volumio volumio[9701]: errno: -16, Jan 11 06:00:15 volumio volumio[9701]: code: 'EBUSY', Jan 11 06:00:15 volumio volumio[9701]: syscall: 'getaddrinfo', Jan 11 06:00:15 volumio volumio[9701]: hostname: 'ws.audioscrobbler.com' Jan 11 06:00:15 volumio volumio[9701]: } Jan 11 06:00:15 volumio volumio[9701]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 06:00:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 06:00:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 06:00:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 06:00:16 volumio sudo[9913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:59 Jan 11 06:00:16 volumio sudo[9913]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:16 volumio sudo[9913]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:16 volumio mpd[9902]: Jan 11 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 06:00:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:00:16 volumio sudo[9885]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:16 volumio sudo[9878]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 06:00:16 volumio systemd[1]: Started dynamicswap service. Jan 11 06:00:16 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 06:00:16 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 06:00:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97480. Jan 11 06:00:16 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 06:00:16 volumio systemd[1]: Started Volumio Backend Module. Jan 11 06:00:16 volumio systemd[1]: Started dynamicswap service. Jan 11 06:00:16 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 06:00:16 volumio systemd[1]: Started Music Player Daemon. Jan 11 06:00:17 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 06:00:17 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 06:00:17 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 06:00:17 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 06:00:17 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 06:00:17 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 06:00:18 volumio volumio[9926]: info: ------------------------------------------- Jan 11 06:00:18 volumio volumio[9926]: info: ----- Volumio3 ---- Jan 11 06:00:18 volumio volumio[9926]: info: ------------------------------------------- Jan 11 06:00:18 volumio volumio[9926]: info: ----- System startup ---- Jan 11 06:00:18 volumio volumio[9926]: info: ------------------------------------------- Jan 11 06:00:18 volumio volumio[9926]: info: MYVOLUMIO Environment detected Jan 11 06:00:19 volumio volumio[9926]: info: Plugin folders cleanup Jan 11 06:00:19 volumio volumio[9926]: info: Scanning into folder /volumio/app/plugins/ Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category audio_interface Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category miscellanea Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category music_service Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category plugins.json Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category system_controller Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category user_interface Jan 11 06:00:19 volumio volumio[9926]: info: Scanning into folder /data/plugins/ Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category system_controller Jan 11 06:00:19 volumio volumio[9926]: info: Scanning category user_interface Jan 11 06:00:19 volumio volumio[9926]: info: Plugin folders cleanup completed Jan 11 06:00:19 volumio volumio[9926]: info: ------------------------------------------- Jan 11 06:00:19 volumio volumio[9926]: info: ----- Core plugins startup ---- Jan 11 06:00:19 volumio volumio[9926]: info: ------------------------------------------- Jan 11 06:00:19 volumio volumio[9926]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 06:00:19 volumio volumio[9926]: info: Adding plugin upnp to MyMusic Plugins Jan 11 06:00:19 volumio volumio[9926]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 06:00:19 volumio volumio[9926]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 06:00:19 volumio volumio[9926]: info: Loading plugins from folder /data/plugins/ Jan 11 06:00:19 volumio volumio[9926]: info: Loading plugin "system"... Jan 11 06:00:19 volumio volumio[9926]: info: Loading plugin "appearance"... Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "network"... Jan 11 06:00:20 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 06:00:20 volumio volumio[9926]: info: Refreshing Cached IP Addresses Jan 11 06:00:20 volumio sudo[9955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 06:00:20 volumio sudo[9955]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:20 volumio sudo[9955]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:20 volumio sudo[9957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 06:00:20 volumio sudo[9957]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:20 volumio sudo[9957]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "services"... Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "alsa_controller"... Jan 11 06:00:20 volumio sudo[9966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 06:00:20 volumio sudo[9966]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:20 volumio sudo[9966]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:20 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "wizard"... Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "networkfs"... Jan 11 06:00:20 volumio volumio[9926]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 06:00:20 volumio volumio[9926]: info: Starting Udev Watcher for removable devices Jan 11 06:00:20 volumio volumio[9926]: info: Ignoring mount for partition: boot Jan 11 06:00:20 volumio volumio[9926]: info: Ignoring mount for partition: volumio Jan 11 06:00:20 volumio volumio[9926]: info: Ignoring mount for partition: volumio_data Jan 11 06:00:20 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "volumio_command_line_client"... Jan 11 06:00:20 volumio volumio[9926]: info: Plugin upnp is not enabled Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "my_music"... Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "mpd"... Jan 11 06:00:20 volumio volumio[9926]: info: Plugin upnp_browser is not enabled Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "alarm-clock"... Jan 11 06:00:20 volumio volumio[9926]: info: Plugin airplay_emulation is not enabled Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "last_100"... Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "webradio"... Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "i2s_dacs"... Jan 11 06:00:20 volumio volumio[9926]: info: I2S DAC not set, start Auto-detection Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "volumiodiscovery"... Jan 11 06:00:20 volumio volumio[9926]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:20 volumio volumio[9926]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:20 volumio volumio[9926]: *** WARNING *** For more information see Jan 11 06:00:20 volumio node[9926]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:20 volumio volumio[9926]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:20 volumio volumio[9926]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:20 volumio volumio[9926]: *** WARNING *** For more information see Jan 11 06:00:20 volumio node[9926]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:20 volumio node[9926]: *** WARNING *** For more information see Jan 11 06:00:20 volumio node[9926]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:20 volumio node[9926]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:20 volumio node[9926]: *** WARNING *** For more information see Jan 11 06:00:20 volumio volumio[9926]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 06:00:20 volumio volumio[9926]: info: Discovery: Started advertising with name: Volumio Jan 11 06:00:20 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:00:20 volumio volumio[9926]: info: Loading plugin "autostart"... Jan 11 06:00:21 volumio volumio[9926]: info: Applying required configuration parameters for plugin autostart Jan 11 06:00:21 volumio volumio[9926]: info: AutoStart - onVolumioStart - read config.json Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "outputs"... Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "albumart"... Jan 11 06:00:21 volumio volumio[9926]: info: Plugin example_plugin is not enabled Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "inputs"... Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "updater_comm"... Jan 11 06:00:21 volumio volumio[9926]: info: Plugin mpdemulation is not enabled Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "rest_api"... Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "websocket"... Jan 11 06:00:21 volumio volumio[9926]: info: Starting Socket.io Server version 2.3.0 Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "backup_restore"... Jan 11 06:00:21 volumio volumio[9926]: Forking 3 albumart workers Jan 11 06:00:21 volumio volumio[9926]: info: Applying required configuration parameters for plugin backup_restore Jan 11 06:00:21 volumio volumio[9926]: info: Loading plugin "Systeminfo"... Jan 11 06:00:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 06:00:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 06:00:22 volumio volumio[9926]: info: Loading plugin "lastfm"... Jan 11 06:00:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 06:00:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 06:00:22 volumio volumio[9926]: Starting albumart workers Jan 11 06:00:22 volumio volumio[9926]: Starting albumart workers Jan 11 06:00:22 volumio volumio[9926]: Starting albumart workers Jan 11 06:00:22 volumio volumio[9926]: info: Loading plugin "randomizer"... Jan 11 06:00:23 volumio volumio-remote-updater[569]: [2025-01-11 06:00:23] [connect] Successful connection Jan 11 06:00:23 volumio volumio[9926]: info: Applying required configuration parameters for plugin randomizer Jan 11 06:00:23 volumio volumio[9926]: info: Loading i18n strings for locale en Jan 11 06:00:23 volumio volumio[9926]: Updating browse sources language Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::initPlayerControls Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: Express server listening on port 3000 Jan 11 06:00:23 volumio volumio[9926]: [Metrics] WebUI: 5s 856.90ms Jan 11 06:00:23 volumio volumio[9926]: info: CoreStateMachine::resetVolumioState Jan 11 06:00:23 volumio volumio[9926]: info: CoreStateMachine::getcurrentVolume Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:00:23 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:00:23 volumio volumio[9926]: info: Volumio Network Manager: Network status updated: 0 Jan 11 06:00:23 volumio volumio[9926]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 06:00:23 volumio volumio[9926]: wlan0 Interface doesn't support scanning : Device or resource busy Jan 11 06:00:23 volumio volumio[9926]: info: Cannot use regular scanning, forcing with ap-force Jan 11 06:00:23 volumio sudo[10044]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 06:00:23 volumio sudo[10044]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:24 volumio wpa_supplicant[847]: wlan0: Trying to associate with SSID 'Hoi' Jan 11 06:00:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 06:00:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 06:00:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 06:00:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 06:00:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 06:00:24 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 06:00:24 volumio sudo[10044]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:24 volumio volumio-remote-updater[569]: [2025-01-11 06:00:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736571623 101 Jan 11 06:00:24 volumio volumio[9926]: 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 Jan 11 06:00:24 volumio volumio[9926]: info: CoreStateMachine::pushState Jan 11 06:00:24 volumio volumio[9926]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:24 volumio volumio[9926]: info: CoreStateMachine::updateTrackBlock Jan 11 06:00:24 volumio volumio[9926]: info: CorePlayQueue::getTrackBlock Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:00:24 volumio volumio[9926]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 06:00:24 volumio volumio[9926]: info: CoreStateMachine::pushState Jan 11 06:00:24 volumio volumio[9926]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:24 volumio volumio[9926]: info: CoreStateMachine::setRepeat true single undefined Jan 11 06:00:24 volumio volumio[9926]: info: CoreStateMachine::pushState Jan 11 06:00:24 volumio volumio[9926]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:24 volumio volumio[9926]: info: CoreStateMachine::setRandom true Jan 11 06:00:24 volumio volumio[9926]: info: CoreStateMachine::pushState Jan 11 06:00:24 volumio volumio[9926]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:24 volumio dhcpcd[859]: wlan0: carrier acquired Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:24 volumio wpa_supplicant[847]: wlan0: Associated with 38:a6:59:ba:aa:ea Jan 11 06:00:24 volumio wpa_supplicant[847]: wlan0: CTRL-EVENT-CONNECTED - Connection to 38:a6:59:ba:aa:ea completed [id=0 id_str=] Jan 11 06:00:24 volumio wpa_supplicant[847]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 11 06:00:24 volumio wpa_supplicant[847]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=NL Jan 11 06:00:24 volumio volumio[9926]: info: Setting Device type: Raspberry PI Jan 11 06:00:24 volumio dhcpcd[859]: wlan0: IAID eb:e1:35:17 Jan 11 06:00:24 volumio dhcpcd[859]: wlan0: carrier lost Jan 11 06:00:24 volumio dhcpcd[859]: wlan0: carrier acquired Jan 11 06:00:24 volumio dhcpcd[859]: wlan0: IAID eb:e1:35:17 Jan 11 06:00:24 volumio volumio[9926]: info: Completed loading Core Plugins Jan 11 06:00:24 volumio volumio[9926]: info: Preparing to generate the ALSA configuration file Jan 11 06:00:24 volumio volumio[9926]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 06:00:24 volumio volumio[9926]: info: Reading ALSA contributions from plugins. Jan 11 06:00:24 volumio volumio[9926]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:00:24 volumio volumio[9926]: info: Output device has changed, restarting MPD Jan 11 06:00:24 volumio sudo[10072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:24 volumio sudo[10072]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:24 volumio volumio[9926]: info: ___________ START PLUGINS ___________ Jan 11 06:00:24 volumio sudo[10072]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:24 volumio volumio[9926]: info: ControllerMpd::onStart: Initializing MPD Jan 11 06:00:24 volumio volumio[9926]: info: Creating MPD Configuration file Jan 11 06:00:24 volumio sudo[10075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:24 volumio sudo[10075]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:24 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 06:00:24 volumio sudo[10078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:24 volumio sudo[10078]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:24 volumio volumio[9926]: info: [1736571624707] CoreMusicLibrary::Adding element Last_100 Jan 11 06:00:24 volumio sudo[10078]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:24 volumio sudo[10081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:24 volumio sudo[10081]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:24 volumio systemd[1]: mpd.service: Succeeded. Jan 11 06:00:24 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:24 volumio volumio[9926]: info: [1736571624766] CoreMusicLibrary::Adding element Webradio Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:24 volumio volumio[9926]: info: Initializing BBC Radios Jan 11 06:00:24 volumio systemd[1]: Starting Music Player Daemon... Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:00:24 volumio volumio[9926]: info: AutoStart - onStart Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:24 volumio volumio[9926]: info: [1736571624865] CoreMusicLibrary::Adding element LastFM Jan 11 06:00:24 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:24 volumio volumio[9926]: Cannot find translation for source LastFM Jan 11 06:00:24 volumio volumio[9926]: info: [LastFM] scrobbler initiated! Jan 11 06:00:24 volumio volumio[9926]: info: [LastFM] extended logging: false Jan 11 06:00:24 volumio volumio[9926]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 06:00:24 volumio volumio[9926]: info: [LastFM] Left init routine Jan 11 06:00:24 volumio volumio[9926]: info: [LastFM] Socket already connected: true Jan 11 06:00:24 volumio volumio[9926]: info: Volumio Calling Home Jan 11 06:00:24 volumio sudo[10083]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:00:24 volumio sudo[10083]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:24 volumio sudo[10083]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:25 volumio dhcpcd[859]: wlan0: rebinding lease of 192.168.2.97 Jan 11 06:00:25 volumio volumio[9926]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:25 volumio volumio[9926]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 06:00:25 volumio volumio[9926]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 06:00:25 volumio volumio[9926]: errno: -16, Jan 11 06:00:25 volumio volumio[9926]: code: 'EBUSY', Jan 11 06:00:25 volumio volumio[9926]: syscall: 'getaddrinfo', Jan 11 06:00:25 volumio volumio[9926]: hostname: 'ws.audioscrobbler.com' Jan 11 06:00:25 volumio volumio[9926]: } Jan 11 06:00:25 volumio volumio[9926]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:25 volumio dhcpcd[859]: wlan0: soliciting an IPv6 router Jan 11 06:00:25 volumio sudo[10108]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:59 Jan 11 06:00:25 volumio sudo[10108]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:25 volumio sudo[10108]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:25 volumio volumio-remote-updater[569]: [2025-01-11 06:00:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 06:00:25 volumio volumio-remote-updater[569]: [2025-01-11 06:00:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 06:00:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 06:00:25 volumio sudo[10075]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:25 volumio sudo[10081]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:26 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 06:00:26 volumio systemd[1]: Started dynamicswap service. Jan 11 06:00:26 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 06:00:26 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 06:00:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 97481. Jan 11 06:00:26 volumio mpd[10098]: Jan 11 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 06:00:26 volumio systemd[1]: Started dynamicswap service. Jan 11 06:00:26 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 06:00:26 volumio systemd[1]: Started Volumio Backend Module. Jan 11 06:00:26 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 06:00:26 volumio systemd[1]: Started Music Player Daemon. Jan 11 06:00:28 volumio volumio[10122]: info: ------------------------------------------- Jan 11 06:00:28 volumio volumio[10122]: info: ----- Volumio3 ---- Jan 11 06:00:28 volumio volumio[10122]: info: ------------------------------------------- Jan 11 06:00:28 volumio volumio[10122]: info: ----- System startup ---- Jan 11 06:00:28 volumio volumio[10122]: info: ------------------------------------------- Jan 11 06:00:28 volumio volumio[10122]: info: MYVOLUMIO Environment detected Jan 11 06:00:28 volumio volumio[10122]: info: Plugin folders cleanup Jan 11 06:00:28 volumio volumio[10122]: info: Scanning into folder /volumio/app/plugins/ Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category audio_interface Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category miscellanea Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category music_service Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category plugins.json Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category system_controller Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category user_interface Jan 11 06:00:28 volumio volumio[10122]: info: Scanning into folder /data/plugins/ Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category system_controller Jan 11 06:00:28 volumio volumio[10122]: info: Scanning category user_interface Jan 11 06:00:28 volumio volumio[10122]: info: Plugin folders cleanup completed Jan 11 06:00:28 volumio volumio[10122]: info: ------------------------------------------- Jan 11 06:00:28 volumio volumio[10122]: info: ----- Core plugins startup ---- Jan 11 06:00:28 volumio volumio[10122]: info: ------------------------------------------- Jan 11 06:00:28 volumio volumio[10122]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 06:00:28 volumio volumio[10122]: info: Adding plugin upnp to MyMusic Plugins Jan 11 06:00:28 volumio volumio[10122]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 06:00:28 volumio volumio[10122]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 06:00:28 volumio volumio[10122]: info: Loading plugins from folder /data/plugins/ Jan 11 06:00:28 volumio volumio[10122]: info: Loading plugin "system"... Jan 11 06:00:28 volumio volumio[10122]: info: Loading plugin "appearance"... Jan 11 06:00:29 volumio volumio[10122]: info: Loading plugin "network"... Jan 11 06:00:29 volumio volumio[10122]: info: Refreshing Cached IP Addresses Jan 11 06:00:29 volumio sudo[10150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 06:00:29 volumio sudo[10150]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:29 volumio sudo[10150]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:29 volumio sudo[10152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 06:00:29 volumio sudo[10152]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:29 volumio sudo[10152]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:29 volumio volumio[10122]: info: Loading plugin "services"... Jan 11 06:00:29 volumio volumio[10122]: info: Loading plugin "alsa_controller"... Jan 11 06:00:29 volumio sudo[10161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 06:00:29 volumio sudo[10161]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:30 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "wizard"... Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "networkfs"... Jan 11 06:00:30 volumio dhcpcd[859]: wlan0: probing for an IPv4LL address Jan 11 06:00:30 volumio volumio[10122]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Jan 11 06:00:30 volumio volumio[10122]: info: Starting Udev Watcher for removable devices Jan 11 06:00:30 volumio volumio[10122]: info: Ignoring mount for partition: boot Jan 11 06:00:30 volumio volumio[10122]: info: Ignoring mount for partition: volumio Jan 11 06:00:30 volumio volumio[10122]: info: Ignoring mount for partition: volumio_data Jan 11 06:00:30 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "volumio_command_line_client"... Jan 11 06:00:30 volumio volumio[10122]: info: Plugin upnp is not enabled Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "my_music"... Jan 11 06:00:30 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Jan 11 06:00:30 volumio dhcpcd[859]: wlan0: DHCP lease expired Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "mpd"... Jan 11 06:00:30 volumio dhcpcd[859]: wlan0: soliciting a DHCP lease Jan 11 06:00:30 volumio dhcpcd[859]: wlan0: offered 192.168.2.97 from 192.168.2.254 `mijnmodem' Jan 11 06:00:30 volumio dhcpcd[859]: wlan0: probing address 192.168.2.97/24 Jan 11 06:00:30 volumio volumio[10122]: info: Plugin upnp_browser is not enabled Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "alarm-clock"... Jan 11 06:00:30 volumio volumio[10122]: info: Plugin airplay_emulation is not enabled Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "last_100"... Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "webradio"... Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "i2s_dacs"... Jan 11 06:00:30 volumio volumio[10122]: info: I2S DAC not set, start Auto-detection Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "volumiodiscovery"... Jan 11 06:00:30 volumio volumio[10122]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:30 volumio volumio[10122]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:30 volumio volumio[10122]: *** WARNING *** For more information see Jan 11 06:00:30 volumio node[10122]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:30 volumio volumio[10122]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:30 volumio volumio[10122]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:30 volumio volumio[10122]: *** WARNING *** For more information see Jan 11 06:00:30 volumio node[10122]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:30 volumio node[10122]: *** WARNING *** For more information see Jan 11 06:00:30 volumio node[10122]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 06:00:30 volumio node[10122]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 06:00:30 volumio node[10122]: *** WARNING *** For more information see Jan 11 06:00:30 volumio volumio[10122]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 06:00:30 volumio volumio[10122]: info: Discovery: Started advertising with name: Volumio Jan 11 06:00:30 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 06:00:30 volumio volumio[10122]: info: Loading plugin "autostart"... Jan 11 06:00:30 volumio volumio-remote-updater[569]: [2025-01-11 06:00:30] [connect] Successful connection Jan 11 06:00:31 volumio volumio[10122]: info: Applying required configuration parameters for plugin autostart Jan 11 06:00:31 volumio volumio[10122]: info: AutoStart - onVolumioStart - read config.json Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "outputs"... Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "albumart"... Jan 11 06:00:31 volumio volumio[10122]: info: Plugin example_plugin is not enabled Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "inputs"... Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "updater_comm"... Jan 11 06:00:31 volumio volumio[10122]: info: Plugin mpdemulation is not enabled Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "rest_api"... Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "websocket"... Jan 11 06:00:31 volumio volumio[10122]: info: Starting Socket.io Server version 2.3.0 Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "backup_restore"... Jan 11 06:00:31 volumio volumio[10122]: Forking 3 albumart workers Jan 11 06:00:31 volumio volumio[10122]: info: Applying required configuration parameters for plugin backup_restore Jan 11 06:00:31 volumio volumio[10122]: info: Loading plugin "Systeminfo"... Jan 11 06:00:32 volumio volumio[10122]: info: Loading plugin "lastfm"... Jan 11 06:00:32 volumio volumio[10122]: Starting albumart workers Jan 11 06:00:32 volumio volumio[10122]: Starting albumart workers Jan 11 06:00:32 volumio volumio[10122]: Starting albumart workers Jan 11 06:00:32 volumio volumio[10122]: info: Loading plugin "randomizer"... Jan 11 06:00:33 volumio sudo[10161]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:33 volumio volumio[10122]: info: Applying required configuration parameters for plugin randomizer Jan 11 06:00:33 volumio volumio[10122]: info: Loading i18n strings for locale en Jan 11 06:00:33 volumio volumio[10122]: Updating browse sources language Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::initPlayerControls Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: Express server listening on port 3000 Jan 11 06:00:33 volumio volumio[10122]: [Metrics] WebUI: 5s 847.93ms Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::resetVolumioState Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::getcurrentVolume Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:00:33 volumio volumio[10122]: info: Volumio Network Manager: Network status updated: 0 Jan 11 06:00:33 volumio volumio-remote-updater[569]: [2025-01-11 06:00:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736571630 101 Jan 11 06:00:33 volumio volumio[10122]: 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 Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::pushState Jan 11 06:00:33 volumio volumio[10122]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::updateTrackBlock Jan 11 06:00:33 volumio volumio[10122]: info: CorePlayQueue::getTrackBlock Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 06:00:33 volumio volumio[10122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::pushState Jan 11 06:00:33 volumio volumio[10122]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::setRepeat true single undefined Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::pushState Jan 11 06:00:33 volumio volumio[10122]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::setRandom true Jan 11 06:00:33 volumio volumio[10122]: info: CoreStateMachine::pushState Jan 11 06:00:33 volumio volumio[10122]: info: CorePlayQueue::getTrack 0 Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:00:33 volumio volumio[10122]: info: CoreCommandRouter::volumioPushState Jan 11 06:00:33 volumio volumio[10122]: info: Setting Device type: Raspberry PI Jan 11 06:00:33 volumio volumio[10122]: info: Completed loading Core Plugins Jan 11 06:00:33 volumio volumio[10122]: info: Preparing to generate the ALSA configuration file Jan 11 06:00:33 volumio volumio[10122]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 11 06:00:33 volumio volumio[10122]: info: Reading ALSA contributions from plugins. Jan 11 06:00:34 volumio volumio[10122]: info: Asound.conf file unchanged, so no further update is needed Jan 11 06:00:34 volumio volumio[10122]: info: Output device has changed, restarting MPD Jan 11 06:00:34 volumio sudo[10259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:34 volumio sudo[10259]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:34 volumio volumio[10122]: info: ___________ START PLUGINS ___________ Jan 11 06:00:34 volumio sudo[10259]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:34 volumio volumio[10122]: info: ControllerMpd::onStart: Initializing MPD Jan 11 06:00:34 volumio volumio[10122]: info: Creating MPD Configuration file Jan 11 06:00:34 volumio sudo[10262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:34 volumio sudo[10262]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:34 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 06:00:34 volumio sudo[10265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 06:00:34 volumio sudo[10265]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:34 volumio sudo[10265]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:34 volumio volumio[10122]: info: [1736571634105] CoreMusicLibrary::Adding element Last_100 Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:34 volumio sudo[10268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 06:00:34 volumio sudo[10268]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:34 volumio volumio[10122]: info: [1736571634137] CoreMusicLibrary::Adding element Webradio Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:34 volumio volumio[10122]: info: Initializing BBC Radios Jan 11 06:00:34 volumio systemd[1]: mpd.service: Succeeded. Jan 11 06:00:34 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 06:00:34 volumio volumio[10122]: info: AutoStart - onStart Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 06:00:34 volumio volumio[10122]: info: [1736571634233] CoreMusicLibrary::Adding element LastFM Jan 11 06:00:34 volumio volumio[10122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 06:00:34 volumio volumio[10122]: Cannot find translation for source LastFM Jan 11 06:00:34 volumio volumio[10122]: info: [LastFM] scrobbler initiated! Jan 11 06:00:34 volumio volumio[10122]: info: [LastFM] extended logging: false Jan 11 06:00:34 volumio volumio[10122]: info: [LastFM] try scrobble stream/radio plays: true Jan 11 06:00:34 volumio systemd[1]: Starting Music Player Daemon... Jan 11 06:00:34 volumio volumio[10122]: info: [LastFM] Left init routine Jan 11 06:00:34 volumio volumio[10122]: info: [LastFM] Socket already connected: true Jan 11 06:00:34 volumio volumio[10122]: info: Volumio Calling Home Jan 11 06:00:34 volumio sudo[10272]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 06:00:34 volumio sudo[10272]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:34 volumio sudo[10272]: pam_unix(sudo:session): session closed for user root Jan 11 06:00:34 volumio dhcpcd[859]: wlan0: using IPv4LL address 169.254.239.57 Jan 11 06:00:34 volumio avahi-daemon[580]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.239.57. Jan 11 06:00:34 volumio dhcpcd[859]: wlan0: adding route to 169.254.0.0/16 Jan 11 06:00:34 volumio dhcpcd[859]: wlan0: adding default route Jan 11 06:00:34 volumio avahi-daemon[580]: New relevant interface wlan0.IPv4 for mDNS. Jan 11 06:00:34 volumio avahi-daemon[580]: Registering new address record for 169.254.239.57 on wlan0.IPv4. Jan 11 06:00:34 volumio volumio[10122]: info: Reloading queue from file Jan 11 06:00:35 volumio volumio[10122]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:35 volumio volumio[10122]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jan 11 06:00:35 volumio volumio[10122]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 11 06:00:35 volumio volumio[10122]: errno: -16, Jan 11 06:00:35 volumio volumio[10122]: code: 'EBUSY', Jan 11 06:00:35 volumio volumio[10122]: syscall: 'getaddrinfo', Jan 11 06:00:35 volumio volumio[10122]: hostname: 'ws.audioscrobbler.com' Jan 11 06:00:35 volumio volumio[10122]: } Jan 11 06:00:35 volumio volumio[10122]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:00:35 volumio sudo[10309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 05:59 Jan 11 06:00:35 volumio sudo[10309]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 06:00:35 volumio dhcpcd[859]: wlan0: leased 192.168.2.97 for 86400 seconds Jan 11 06:00:35 volumio avahi-daemon[580]: Registering new address record for 192.168.2.97 on wlan0.IPv4. Jan 11 06:00:35 volumio dhcpcd[859]: wlan0: adding route to 192.168.2.0/24 Jan 11 06:00:35 volumio dhcpcd[859]: wlan0: changing default route via 192.168.2.254 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"