-- Logs begin at Thu 2024-09-05 05:32:47 CEST, end at Thu 2024-09-05 06:01:30 CEST. -- Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "network"... Sep 05 06:00:00 volumio volumio[9210]: info: Refreshing Cached IP Addresses Sep 05 06:00:00 volumio sudo[9239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:00:00 volumio sudo[9239]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:00 volumio sudo[9239]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:00 volumio sudo[9241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:00:00 volumio sudo[9241]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "services"... Sep 05 06:00:00 volumio sudo[9241]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "alsa_controller"... Sep 05 06:00:00 volumio sudo[9244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:00:00 volumio sudo[9244]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:00 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "wizard"... Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "networkfs"... Sep 05 06:00:00 volumio volumio[9210]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:00:00 volumio volumio[9210]: info: Starting Udev Watcher for removable devices Sep 05 06:00:00 volumio volumio[9210]: info: Ignoring mount for partition: boot Sep 05 06:00:00 volumio volumio[9210]: info: Ignoring mount for partition: volumio Sep 05 06:00:00 volumio volumio[9210]: info: Ignoring mount for partition: volumio_data Sep 05 06:00:00 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:00:00 volumio volumio[9210]: info: Plugin upnp is not enabled Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "my_music"... Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "mpd"... Sep 05 06:00:00 volumio volumio[9210]: info: Plugin upnp_browser is not enabled Sep 05 06:00:00 volumio volumio[9210]: info: Loading plugin "alarm-clock"... Sep 05 06:00:01 volumio volumio[9210]: info: Plugin airplay_emulation is not enabled Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "last_100"... Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "webradio"... Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "i2s_dacs"... Sep 05 06:00:01 volumio volumio[9210]: info: I2S DAC not set, start Auto-detection Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "volumiodiscovery"... Sep 05 06:00:01 volumio volumio-remote-updater[562]: [2024-09-05 06:00:01] [connect] Successful connection Sep 05 06:00:01 volumio volumio[9210]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:01 volumio volumio[9210]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:01 volumio volumio[9210]: *** WARNING *** For more information see Sep 05 06:00:01 volumio node[9210]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:01 volumio volumio[9210]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:01 volumio volumio[9210]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:01 volumio volumio[9210]: *** WARNING *** For more information see Sep 05 06:00:01 volumio node[9210]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:01 volumio node[9210]: *** WARNING *** For more information see Sep 05 06:00:01 volumio node[9210]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:01 volumio node[9210]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:01 volumio node[9210]: *** WARNING *** For more information see Sep 05 06:00:01 volumio volumio[9210]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:00:01 volumio volumio[9210]: info: Discovery: Started advertising with name: Volumio Sep 05 06:00:01 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "autostart"... Sep 05 06:00:01 volumio volumio[9210]: info: Applying required configuration parameters for plugin autostart Sep 05 06:00:01 volumio volumio[9210]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "outputs"... Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "albumart"... Sep 05 06:00:01 volumio volumio[9210]: info: Plugin example_plugin is not enabled Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "inputs"... Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "updater_comm"... Sep 05 06:00:01 volumio volumio[9210]: info: Plugin mpdemulation is not enabled Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "rest_api"... Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "websocket"... Sep 05 06:00:01 volumio volumio[9210]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:00:01 volumio volumio[9210]: info: Loading plugin "backup_restore"... Sep 05 06:00:02 volumio volumio[9210]: Forking 3 albumart workers Sep 05 06:00:02 volumio volumio[9210]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:00:02 volumio volumio[9210]: info: Loading plugin "Systeminfo"... Sep 05 06:00:02 volumio volumio[9210]: info: Loading plugin "lastfm"... Sep 05 06:00:03 volumio volumio[9210]: Starting albumart workers Sep 05 06:00:03 volumio volumio[9210]: Starting albumart workers Sep 05 06:00:03 volumio volumio[9210]: Starting albumart workers Sep 05 06:00:03 volumio volumio[9210]: info: Loading plugin "randomizer"... Sep 05 06:00:03 volumio volumio[9210]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:00:04 volumio volumio[9210]: info: Loading i18n strings for locale en Sep 05 06:00:04 volumio volumio[9210]: Updating browse sources language Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::initPlayerControls Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: Express server listening on port 3000 Sep 05 06:00:04 volumio volumio[9210]: [Metrics] WebUI: 6s 430.05ms Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::resetVolumioState Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::getcurrentVolume Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:04 volumio volumio-remote-updater[562]: [2024-09-05 06:00:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725508801 101 Sep 05 06:00:04 volumio volumio[9210]: 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 Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::pushState Sep 05 06:00:04 volumio volumio[9210]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::updateTrackBlock Sep 05 06:00:04 volumio volumio[9210]: info: CorePlayQueue::getTrackBlock Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:04 volumio volumio[9210]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::pushState Sep 05 06:00:04 volumio volumio[9210]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::pushState Sep 05 06:00:04 volumio volumio[9210]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::setRandom true Sep 05 06:00:04 volumio volumio[9210]: info: CoreStateMachine::pushState Sep 05 06:00:04 volumio volumio[9210]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:04 volumio volumio[9210]: info: Setting Device type: Raspberry PI Sep 05 06:00:04 volumio volumio[9210]: info: Completed loading Core Plugins Sep 05 06:00:04 volumio volumio[9210]: info: Preparing to generate the ALSA configuration file Sep 05 06:00:04 volumio volumio[9210]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:00:04 volumio volumio[9210]: info: Reading ALSA contributions from plugins. Sep 05 06:00:04 volumio volumio[9210]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:00:04 volumio volumio[9210]: info: Output device has changed, restarting MPD Sep 05 06:00:04 volumio sudo[9323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:04 volumio sudo[9323]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:04 volumio volumio[9210]: info: ___________ START PLUGINS ___________ Sep 05 06:00:04 volumio sudo[9323]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:04 volumio volumio[9210]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:00:04 volumio volumio[9210]: info: Creating MPD Configuration file Sep 05 06:00:04 volumio sudo[9325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:04 volumio sudo[9325]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:04 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:00:04 volumio sudo[9329]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:04 volumio sudo[9329]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:04 volumio volumio[9210]: info: [1725508804845] CoreMusicLibrary::Adding element Last_100 Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:04 volumio sudo[9329]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:04 volumio sudo[9331]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:04 volumio sudo[9331]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:04 volumio volumio[9210]: info: [1725508804859] CoreMusicLibrary::Adding element Webradio Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:04 volumio volumio[9210]: info: Initializing BBC Radios Sep 05 06:00:04 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:04 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:04 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:04 volumio volumio[9210]: info: AutoStart - onStart Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:04 volumio volumio[9210]: info: [1725508804975] CoreMusicLibrary::Adding element LastFM Sep 05 06:00:04 volumio volumio[9210]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:04 volumio volumio[9210]: Cannot find translation for source LastFM Sep 05 06:00:04 volumio volumio[9210]: info: [LastFM] scrobbler initiated! Sep 05 06:00:04 volumio volumio[9210]: info: [LastFM] extended logging: false Sep 05 06:00:04 volumio volumio[9210]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:00:04 volumio volumio[9210]: info: [LastFM] Left init routine Sep 05 06:00:04 volumio volumio[9210]: info: [LastFM] Socket already connected: true Sep 05 06:00:05 volumio volumio[9210]: info: Volumio Calling Home Sep 05 06:00:05 volumio sudo[9336]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:00:05 volumio sudo[9336]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:05 volumio sudo[9336]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:05 volumio volumio[9210]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:05 volumio volumio[9210]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:00:05 volumio volumio[9210]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:00:05 volumio volumio[9210]: errno: -16, Sep 05 06:00:05 volumio volumio[9210]: code: 'EBUSY', Sep 05 06:00:05 volumio volumio[9210]: syscall: 'getaddrinfo', Sep 05 06:00:05 volumio volumio[9210]: hostname: 'ws.audioscrobbler.com' Sep 05 06:00:05 volumio volumio[9210]: } Sep 05 06:00:05 volumio volumio[9210]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:05 volumio wpa_supplicant[849]: wlan0: Failed to initiate sched scan Sep 05 06:00:05 volumio sudo[9244]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:05 volumio sudo[9359]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 05:59 Sep 05 06:00:05 volumio sudo[9359]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:06 volumio sudo[9359]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:06 volumio volumio-remote-updater[562]: [2024-09-05 06:00:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 05 06:00:06 volumio volumio-remote-updater[562]: [2024-09-05 06:00:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 05 06:00:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:00:06 volumio sudo[9331]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:06 volumio sudo[9325]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:00:06 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:06 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:06 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:00:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8613. Sep 05 06:00:06 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:06 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:00:06 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:00:06 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:06 volumio mpd[9349]: Sep 05 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:00:07 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:00:08 volumio volumio[9373]: info: ------------------------------------------- Sep 05 06:00:08 volumio volumio[9373]: info: ----- Volumio3 ---- Sep 05 06:00:08 volumio volumio[9373]: info: ------------------------------------------- Sep 05 06:00:08 volumio volumio[9373]: info: ----- System startup ---- Sep 05 06:00:08 volumio volumio[9373]: info: ------------------------------------------- Sep 05 06:00:09 volumio volumio[9373]: info: MYVOLUMIO Environment detected Sep 05 06:00:09 volumio volumio[9373]: info: Plugin folders cleanup Sep 05 06:00:09 volumio volumio[9373]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category audio_interface Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category miscellanea Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category music_service Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category plugins.json Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category system_controller Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category user_interface Sep 05 06:00:09 volumio volumio[9373]: info: Scanning into folder /data/plugins/ Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category system_controller Sep 05 06:00:09 volumio volumio[9373]: info: Scanning category user_interface Sep 05 06:00:09 volumio volumio[9373]: info: Plugin folders cleanup completed Sep 05 06:00:09 volumio volumio[9373]: info: ------------------------------------------- Sep 05 06:00:09 volumio volumio[9373]: info: ----- Core plugins startup ---- Sep 05 06:00:09 volumio volumio[9373]: info: ------------------------------------------- Sep 05 06:00:09 volumio volumio[9373]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:00:09 volumio volumio[9373]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:00:09 volumio volumio[9373]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:00:09 volumio volumio[9373]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:00:09 volumio volumio[9373]: info: Loading plugins from folder /data/plugins/ Sep 05 06:00:09 volumio volumio[9373]: info: Loading plugin "system"... Sep 05 06:00:09 volumio volumio[9373]: info: Loading plugin "appearance"... Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "network"... Sep 05 06:00:10 volumio volumio[9373]: info: Refreshing Cached IP Addresses Sep 05 06:00:10 volumio sudo[9401]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:00:10 volumio sudo[9401]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:10 volumio sudo[9401]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:10 volumio sudo[9403]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "services"... Sep 05 06:00:10 volumio sudo[9403]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "alsa_controller"... Sep 05 06:00:10 volumio sudo[9403]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:10 volumio sudo[9406]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:00:10 volumio sudo[9406]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:10 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "wizard"... Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "networkfs"... Sep 05 06:00:10 volumio volumio[9373]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:00:10 volumio volumio[9373]: info: Starting Udev Watcher for removable devices Sep 05 06:00:10 volumio volumio[9373]: info: Ignoring mount for partition: boot Sep 05 06:00:10 volumio volumio[9373]: info: Ignoring mount for partition: volumio Sep 05 06:00:10 volumio volumio[9373]: info: Ignoring mount for partition: volumio_data Sep 05 06:00:10 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:00:10 volumio volumio[9373]: info: Plugin upnp is not enabled Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "my_music"... Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "mpd"... Sep 05 06:00:10 volumio volumio[9373]: info: Plugin upnp_browser is not enabled Sep 05 06:00:10 volumio volumio[9373]: info: Loading plugin "alarm-clock"... Sep 05 06:00:11 volumio volumio[9373]: info: Plugin airplay_emulation is not enabled Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "last_100"... Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "webradio"... Sep 05 06:00:11 volumio volumio-remote-updater[562]: [2024-09-05 06:00:11] [connect] Successful connection Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "i2s_dacs"... Sep 05 06:00:11 volumio volumio[9373]: info: I2S DAC not set, start Auto-detection Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "volumiodiscovery"... Sep 05 06:00:11 volumio volumio[9373]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:11 volumio volumio[9373]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:11 volumio volumio[9373]: *** WARNING *** For more information see Sep 05 06:00:11 volumio node[9373]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:11 volumio volumio[9373]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:11 volumio volumio[9373]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:11 volumio volumio[9373]: *** WARNING *** For more information see Sep 05 06:00:11 volumio node[9373]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:11 volumio node[9373]: *** WARNING *** For more information see Sep 05 06:00:11 volumio node[9373]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:11 volumio node[9373]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:11 volumio node[9373]: *** WARNING *** For more information see Sep 05 06:00:11 volumio volumio[9373]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:00:11 volumio volumio[9373]: info: Discovery: Started advertising with name: Volumio Sep 05 06:00:11 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "autostart"... Sep 05 06:00:11 volumio volumio[9373]: info: Applying required configuration parameters for plugin autostart Sep 05 06:00:11 volumio volumio[9373]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "outputs"... Sep 05 06:00:11 volumio ntpd[755]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "albumart"... Sep 05 06:00:11 volumio volumio[9373]: info: Plugin example_plugin is not enabled Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "inputs"... Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "updater_comm"... Sep 05 06:00:11 volumio volumio[9373]: info: Plugin mpdemulation is not enabled Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "rest_api"... Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "websocket"... Sep 05 06:00:11 volumio volumio[9373]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:00:11 volumio volumio[9373]: info: Loading plugin "backup_restore"... Sep 05 06:00:12 volumio volumio[9373]: Forking 3 albumart workers Sep 05 06:00:12 volumio volumio[9373]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:00:12 volumio volumio[9373]: info: Loading plugin "Systeminfo"... Sep 05 06:00:12 volumio volumio[9373]: info: Loading plugin "lastfm"... Sep 05 06:00:13 volumio volumio[9373]: Starting albumart workers Sep 05 06:00:13 volumio volumio[9373]: Starting albumart workers Sep 05 06:00:13 volumio volumio[9373]: Starting albumart workers Sep 05 06:00:13 volumio volumio[9373]: info: Loading plugin "randomizer"... Sep 05 06:00:13 volumio volumio[9373]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:00:13 volumio volumio[9373]: info: Loading i18n strings for locale en Sep 05 06:00:13 volumio volumio[9373]: Updating browse sources language Sep 05 06:00:13 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::initPlayerControls Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:14 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: Express server listening on port 3000 Sep 05 06:00:14 volumio volumio[9373]: [Metrics] WebUI: 6s 258.10ms Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::resetVolumioState Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::getcurrentVolume Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:14 volumio volumio-remote-updater[562]: [2024-09-05 06:00:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725508811 101 Sep 05 06:00:14 volumio volumio[9373]: 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 Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::pushState Sep 05 06:00:14 volumio volumio[9373]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::updateTrackBlock Sep 05 06:00:14 volumio volumio[9373]: info: CorePlayQueue::getTrackBlock Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:14 volumio volumio[9373]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::pushState Sep 05 06:00:14 volumio volumio[9373]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::pushState Sep 05 06:00:14 volumio volumio[9373]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::setRandom true Sep 05 06:00:14 volumio volumio[9373]: info: CoreStateMachine::pushState Sep 05 06:00:14 volumio volumio[9373]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:14 volumio volumio[9373]: info: Setting Device type: Raspberry PI Sep 05 06:00:14 volumio volumio[9373]: info: Completed loading Core Plugins Sep 05 06:00:14 volumio volumio[9373]: info: Preparing to generate the ALSA configuration file Sep 05 06:00:14 volumio volumio[9373]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:00:14 volumio volumio[9373]: info: Reading ALSA contributions from plugins. Sep 05 06:00:14 volumio volumio[9373]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:00:14 volumio volumio[9373]: info: Output device has changed, restarting MPD Sep 05 06:00:14 volumio sudo[9485]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:14 volumio sudo[9485]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:14 volumio volumio[9373]: info: ___________ START PLUGINS ___________ Sep 05 06:00:14 volumio sudo[9485]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:14 volumio volumio[9373]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:00:14 volumio volumio[9373]: info: Creating MPD Configuration file Sep 05 06:00:14 volumio sudo[9487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:14 volumio sudo[9487]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:14 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:00:14 volumio sudo[9491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:14 volumio sudo[9491]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:14 volumio sudo[9491]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:14 volumio volumio[9373]: info: [1725508814715] CoreMusicLibrary::Adding element Last_100 Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:14 volumio sudo[9494]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:14 volumio sudo[9494]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:14 volumio volumio[9373]: info: [1725508814730] CoreMusicLibrary::Adding element Webradio Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:14 volumio volumio[9373]: info: Initializing BBC Radios Sep 05 06:00:14 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:14 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:14 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:14 volumio volumio[9373]: info: AutoStart - onStart Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:14 volumio volumio[9373]: info: [1725508814848] CoreMusicLibrary::Adding element LastFM Sep 05 06:00:14 volumio volumio[9373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:14 volumio volumio[9373]: Cannot find translation for source LastFM Sep 05 06:00:14 volumio volumio[9373]: info: [LastFM] scrobbler initiated! Sep 05 06:00:14 volumio volumio[9373]: info: [LastFM] extended logging: false Sep 05 06:00:14 volumio volumio[9373]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:00:14 volumio volumio[9373]: info: [LastFM] Left init routine Sep 05 06:00:14 volumio volumio[9373]: info: [LastFM] Socket already connected: true Sep 05 06:00:14 volumio volumio[9373]: info: Volumio Calling Home Sep 05 06:00:14 volumio sudo[9498]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:00:14 volumio sudo[9498]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:14 volumio sudo[9498]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:15 volumio volumio[9373]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:15 volumio volumio[9373]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:00:15 volumio volumio[9373]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:00:15 volumio volumio[9373]: errno: -16, Sep 05 06:00:15 volumio volumio[9373]: code: 'EBUSY', Sep 05 06:00:15 volumio volumio[9373]: syscall: 'getaddrinfo', Sep 05 06:00:15 volumio volumio[9373]: hostname: 'ws.audioscrobbler.com' Sep 05 06:00:15 volumio volumio[9373]: } Sep 05 06:00:15 volumio volumio[9373]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:15 volumio wpa_supplicant[849]: wlan0: Trying to associate with SSID 'Hoi' Sep 05 06:00:15 volumio sudo[9406]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:15 volumio sudo[9521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 05:59 Sep 05 06:00:15 volumio sudo[9521]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:15 volumio sudo[9521]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:16 volumio volumio-remote-updater[562]: [2024-09-05 06:00:16] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 05 06:00:16 volumio volumio-remote-updater[562]: [2024-09-05 06:00:16] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 05 06:00:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:00:16 volumio sudo[9487]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:16 volumio sudo[9494]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:00:16 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:16 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:16 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:00:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8614. Sep 05 06:00:16 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:16 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:00:16 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:00:16 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:16 volumio mpd[9510]: Sep 05 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:00:17 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:00:18 volumio wpa_supplicant[849]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Sep 05 06:00:18 volumio wpa_supplicant[849]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Hoi" auth_failures=3 duration=55 reason=CONN_FAILED Sep 05 06:00:18 volumio volumio[9535]: info: ------------------------------------------- Sep 05 06:00:18 volumio volumio[9535]: info: ----- Volumio3 ---- Sep 05 06:00:18 volumio volumio[9535]: info: ------------------------------------------- Sep 05 06:00:18 volumio volumio[9535]: info: ----- System startup ---- Sep 05 06:00:18 volumio volumio[9535]: info: ------------------------------------------- Sep 05 06:00:19 volumio volumio[9535]: info: MYVOLUMIO Environment detected Sep 05 06:00:19 volumio volumio[9535]: info: Plugin folders cleanup Sep 05 06:00:19 volumio volumio[9535]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category audio_interface Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category miscellanea Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category music_service Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category plugins.json Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category system_controller Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category user_interface Sep 05 06:00:19 volumio volumio[9535]: info: Scanning into folder /data/plugins/ Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category system_controller Sep 05 06:00:19 volumio volumio[9535]: info: Scanning category user_interface Sep 05 06:00:19 volumio volumio[9535]: info: Plugin folders cleanup completed Sep 05 06:00:19 volumio volumio[9535]: info: ------------------------------------------- Sep 05 06:00:19 volumio volumio[9535]: info: ----- Core plugins startup ---- Sep 05 06:00:19 volumio volumio[9535]: info: ------------------------------------------- Sep 05 06:00:19 volumio volumio[9535]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:00:19 volumio volumio[9535]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:00:19 volumio volumio[9535]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:00:19 volumio volumio[9535]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:00:19 volumio volumio[9535]: info: Loading plugins from folder /data/plugins/ Sep 05 06:00:19 volumio volumio[9535]: info: Loading plugin "system"... Sep 05 06:00:19 volumio volumio[9535]: info: Loading plugin "appearance"... Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "network"... Sep 05 06:00:20 volumio volumio[9535]: info: Refreshing Cached IP Addresses Sep 05 06:00:20 volumio sudo[9563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:00:20 volumio sudo[9563]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:20 volumio sudo[9563]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:20 volumio sudo[9565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "services"... Sep 05 06:00:20 volumio sudo[9565]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "alsa_controller"... Sep 05 06:00:20 volumio sudo[9565]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:20 volumio sudo[9568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:00:20 volumio sudo[9568]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:20 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "wizard"... Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "networkfs"... Sep 05 06:00:20 volumio volumio[9535]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:00:20 volumio volumio[9535]: info: Starting Udev Watcher for removable devices Sep 05 06:00:20 volumio volumio[9535]: info: Ignoring mount for partition: boot Sep 05 06:00:20 volumio volumio[9535]: info: Ignoring mount for partition: volumio Sep 05 06:00:20 volumio volumio[9535]: info: Ignoring mount for partition: volumio_data Sep 05 06:00:20 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:00:20 volumio volumio[9535]: info: Plugin upnp is not enabled Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "my_music"... Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "mpd"... Sep 05 06:00:20 volumio ntpd[755]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 05 06:00:20 volumio volumio[9535]: info: Plugin upnp_browser is not enabled Sep 05 06:00:20 volumio volumio[9535]: info: Loading plugin "alarm-clock"... Sep 05 06:00:21 volumio volumio-remote-updater[562]: [2024-09-05 06:00:21] [connect] Successful connection Sep 05 06:00:21 volumio volumio[9535]: info: Plugin airplay_emulation is not enabled Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "last_100"... Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "webradio"... Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "i2s_dacs"... Sep 05 06:00:21 volumio volumio[9535]: info: I2S DAC not set, start Auto-detection Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "volumiodiscovery"... Sep 05 06:00:21 volumio volumio[9535]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:21 volumio volumio[9535]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:21 volumio volumio[9535]: *** WARNING *** For more information see Sep 05 06:00:21 volumio node[9535]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:21 volumio volumio[9535]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:21 volumio volumio[9535]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:21 volumio volumio[9535]: *** WARNING *** For more information see Sep 05 06:00:21 volumio node[9535]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:21 volumio node[9535]: *** WARNING *** For more information see Sep 05 06:00:21 volumio node[9535]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:21 volumio node[9535]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:21 volumio node[9535]: *** WARNING *** For more information see Sep 05 06:00:21 volumio volumio[9535]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:00:21 volumio volumio[9535]: info: Discovery: Started advertising with name: Volumio Sep 05 06:00:21 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "autostart"... Sep 05 06:00:21 volumio volumio[9535]: info: Applying required configuration parameters for plugin autostart Sep 05 06:00:21 volumio volumio[9535]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "outputs"... Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "albumart"... Sep 05 06:00:21 volumio volumio[9535]: info: Plugin example_plugin is not enabled Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "inputs"... Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "updater_comm"... Sep 05 06:00:21 volumio volumio[9535]: info: Plugin mpdemulation is not enabled Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "rest_api"... Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "websocket"... Sep 05 06:00:21 volumio volumio[9535]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:00:21 volumio volumio[9535]: info: Loading plugin "backup_restore"... Sep 05 06:00:22 volumio volumio[9535]: Forking 3 albumart workers Sep 05 06:00:22 volumio volumio[9535]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:00:22 volumio volumio[9535]: info: Loading plugin "Systeminfo"... Sep 05 06:00:22 volumio volumio[9535]: info: Loading plugin "lastfm"... Sep 05 06:00:22 volumio sudo[9568]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:23 volumio volumio[9535]: Starting albumart workers Sep 05 06:00:23 volumio volumio[9535]: Starting albumart workers Sep 05 06:00:23 volumio volumio[9535]: Starting albumart workers Sep 05 06:00:23 volumio volumio[9535]: info: Loading plugin "randomizer"... Sep 05 06:00:23 volumio volumio[9535]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:00:23 volumio volumio[9535]: info: Loading i18n strings for locale en Sep 05 06:00:23 volumio volumio[9535]: Updating browse sources language Sep 05 06:00:23 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:23 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::initPlayerControls Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: Express server listening on port 3000 Sep 05 06:00:24 volumio volumio[9535]: [Metrics] WebUI: 6s 238.77ms Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::resetVolumioState Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::getcurrentVolume Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:24 volumio volumio-remote-updater[562]: [2024-09-05 06:00:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725508821 101 Sep 05 06:00:24 volumio volumio[9535]: 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 Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::pushState Sep 05 06:00:24 volumio volumio[9535]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::updateTrackBlock Sep 05 06:00:24 volumio volumio[9535]: info: CorePlayQueue::getTrackBlock Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:24 volumio volumio[9535]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::pushState Sep 05 06:00:24 volumio volumio[9535]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::setRandom true Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::pushState Sep 05 06:00:24 volumio volumio[9535]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:24 volumio volumio[9535]: info: Setting Device type: Raspberry PI Sep 05 06:00:24 volumio volumio[9535]: info: CoreStateMachine::pushState Sep 05 06:00:24 volumio volumio[9535]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:24 volumio volumio[9535]: info: Completed loading Core Plugins Sep 05 06:00:24 volumio volumio[9535]: info: Preparing to generate the ALSA configuration file Sep 05 06:00:24 volumio volumio[9535]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:00:24 volumio volumio[9535]: info: Reading ALSA contributions from plugins. Sep 05 06:00:24 volumio volumio[9535]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:00:24 volumio volumio[9535]: info: Output device has changed, restarting MPD Sep 05 06:00:24 volumio sudo[9647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:24 volumio sudo[9647]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:24 volumio sudo[9647]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:24 volumio volumio[9535]: info: ___________ START PLUGINS ___________ Sep 05 06:00:24 volumio volumio[9535]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:00:24 volumio volumio[9535]: info: Creating MPD Configuration file Sep 05 06:00:24 volumio sudo[9650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:24 volumio sudo[9650]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:24 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:00:24 volumio sudo[9653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:24 volumio sudo[9653]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:24 volumio volumio[9535]: info: [1725508824652] CoreMusicLibrary::Adding element Last_100 Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:24 volumio volumio[9535]: info: [1725508824663] CoreMusicLibrary::Adding element Webradio Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:24 volumio sudo[9653]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:24 volumio sudo[9655]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:24 volumio sudo[9655]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:24 volumio volumio[9535]: info: Initializing BBC Radios Sep 05 06:00:24 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:24 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:24 volumio volumio[9535]: info: AutoStart - onStart Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:24 volumio volumio[9535]: info: [1725508824799] CoreMusicLibrary::Adding element LastFM Sep 05 06:00:24 volumio volumio[9535]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:24 volumio volumio[9535]: Cannot find translation for source LastFM Sep 05 06:00:24 volumio volumio[9535]: info: [LastFM] scrobbler initiated! Sep 05 06:00:24 volumio volumio[9535]: info: [LastFM] extended logging: false Sep 05 06:00:24 volumio volumio[9535]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:00:24 volumio volumio[9535]: info: [LastFM] Left init routine Sep 05 06:00:24 volumio volumio[9535]: info: [LastFM] Socket already connected: true Sep 05 06:00:24 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:24 volumio volumio[9535]: info: Volumio Calling Home Sep 05 06:00:24 volumio sudo[9660]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:00:24 volumio sudo[9660]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:24 volumio sudo[9660]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:25 volumio volumio[9535]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:25 volumio volumio[9535]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:00:25 volumio volumio[9535]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:00:25 volumio volumio[9535]: errno: -16, Sep 05 06:00:25 volumio volumio[9535]: code: 'EBUSY', Sep 05 06:00:25 volumio volumio[9535]: syscall: 'getaddrinfo', Sep 05 06:00:25 volumio volumio[9535]: hostname: 'ws.audioscrobbler.com' Sep 05 06:00:25 volumio volumio[9535]: } Sep 05 06:00:25 volumio volumio[9535]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:25 volumio sudo[9683]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 05:59 Sep 05 06:00:25 volumio sudo[9683]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:25 volumio sudo[9683]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:26 volumio volumio-remote-updater[562]: [2024-09-05 06:00:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 05 06:00:26 volumio volumio-remote-updater[562]: [2024-09-05 06:00:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 05 06:00:26 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:00:26 volumio sudo[9650]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:26 volumio sudo[9655]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:26 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:00:26 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:26 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:26 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:00:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8615. Sep 05 06:00:26 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:26 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:00:26 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:00:26 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:26 volumio mpd[9673]: Sep 05 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:00:27 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:00:28 volumio volumio[9697]: info: ------------------------------------------- Sep 05 06:00:28 volumio volumio[9697]: info: ----- Volumio3 ---- Sep 05 06:00:28 volumio volumio[9697]: info: ------------------------------------------- Sep 05 06:00:28 volumio volumio[9697]: info: ----- System startup ---- Sep 05 06:00:28 volumio volumio[9697]: info: ------------------------------------------- Sep 05 06:00:29 volumio volumio[9697]: info: MYVOLUMIO Environment detected Sep 05 06:00:29 volumio volumio[9697]: info: Plugin folders cleanup Sep 05 06:00:29 volumio volumio[9697]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category audio_interface Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category miscellanea Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category music_service Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category plugins.json Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category system_controller Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category user_interface Sep 05 06:00:29 volumio volumio[9697]: info: Scanning into folder /data/plugins/ Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category system_controller Sep 05 06:00:29 volumio volumio[9697]: info: Scanning category user_interface Sep 05 06:00:29 volumio volumio[9697]: info: Plugin folders cleanup completed Sep 05 06:00:29 volumio volumio[9697]: info: ------------------------------------------- Sep 05 06:00:29 volumio volumio[9697]: info: ----- Core plugins startup ---- Sep 05 06:00:29 volumio volumio[9697]: info: ------------------------------------------- Sep 05 06:00:29 volumio volumio[9697]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:00:29 volumio volumio[9697]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:00:29 volumio volumio[9697]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:00:29 volumio volumio[9697]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:00:29 volumio volumio[9697]: info: Loading plugins from folder /data/plugins/ Sep 05 06:00:29 volumio volumio[9697]: info: Loading plugin "system"... Sep 05 06:00:29 volumio volumio[9697]: info: Loading plugin "appearance"... Sep 05 06:00:29 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "network"... Sep 05 06:00:30 volumio volumio[9697]: info: Refreshing Cached IP Addresses Sep 05 06:00:30 volumio sudo[9763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:00:30 volumio sudo[9763]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:30 volumio sudo[9765]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "services"... Sep 05 06:00:30 volumio sudo[9765]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "alsa_controller"... Sep 05 06:00:30 volumio sudo[9765]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:30 volumio sudo[9763]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:30 volumio sudo[9768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:00:30 volumio sudo[9768]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:30 volumio sudo[9768]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:30 volumio wpa_supplicant[849]: wlan0: Failed to initiate sched scan Sep 05 06:00:30 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "wizard"... Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "networkfs"... Sep 05 06:00:30 volumio volumio[9697]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:00:30 volumio volumio[9697]: info: Starting Udev Watcher for removable devices Sep 05 06:00:30 volumio volumio[9697]: info: Ignoring mount for partition: boot Sep 05 06:00:30 volumio volumio[9697]: info: Ignoring mount for partition: volumio Sep 05 06:00:30 volumio volumio[9697]: info: Ignoring mount for partition: volumio_data Sep 05 06:00:30 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:00:30 volumio volumio[9697]: info: Plugin upnp is not enabled Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "my_music"... Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "mpd"... Sep 05 06:00:30 volumio volumio[9697]: info: Plugin upnp_browser is not enabled Sep 05 06:00:30 volumio volumio[9697]: info: Loading plugin "alarm-clock"... Sep 05 06:00:31 volumio volumio-remote-updater[562]: [2024-09-05 06:00:31] [connect] Successful connection Sep 05 06:00:31 volumio volumio[9697]: info: Plugin airplay_emulation is not enabled Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "last_100"... Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "webradio"... Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "i2s_dacs"... Sep 05 06:00:31 volumio volumio[9697]: info: I2S DAC not set, start Auto-detection Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "volumiodiscovery"... Sep 05 06:00:31 volumio volumio[9697]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:31 volumio volumio[9697]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:31 volumio volumio[9697]: *** WARNING *** For more information see Sep 05 06:00:31 volumio node[9697]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:31 volumio volumio[9697]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:31 volumio volumio[9697]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:31 volumio volumio[9697]: *** WARNING *** For more information see Sep 05 06:00:31 volumio node[9697]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:31 volumio node[9697]: *** WARNING *** For more information see Sep 05 06:00:31 volumio node[9697]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:31 volumio node[9697]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:31 volumio node[9697]: *** WARNING *** For more information see Sep 05 06:00:31 volumio volumio[9697]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:00:31 volumio volumio[9697]: info: Discovery: Started advertising with name: Volumio Sep 05 06:00:31 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "autostart"... Sep 05 06:00:31 volumio volumio[9697]: info: Applying required configuration parameters for plugin autostart Sep 05 06:00:31 volumio volumio[9697]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "outputs"... Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "albumart"... Sep 05 06:00:31 volumio volumio[9697]: info: Plugin example_plugin is not enabled Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "inputs"... Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "updater_comm"... Sep 05 06:00:31 volumio volumio[9697]: info: Plugin mpdemulation is not enabled Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "rest_api"... Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "websocket"... Sep 05 06:00:31 volumio volumio[9697]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:00:31 volumio volumio[9697]: info: Loading plugin "backup_restore"... Sep 05 06:00:32 volumio volumio[9697]: Forking 3 albumart workers Sep 05 06:00:32 volumio volumio[9697]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:00:32 volumio volumio[9697]: info: Loading plugin "Systeminfo"... Sep 05 06:00:32 volumio volumio[9697]: info: Loading plugin "lastfm"... Sep 05 06:00:33 volumio volumio[9697]: Starting albumart workers Sep 05 06:00:33 volumio volumio[9697]: Starting albumart workers Sep 05 06:00:33 volumio volumio[9697]: Starting albumart workers Sep 05 06:00:33 volumio volumio[9697]: info: Loading plugin "randomizer"... Sep 05 06:00:33 volumio volumio[9697]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:00:33 volumio volumio[9697]: info: Loading i18n strings for locale en Sep 05 06:00:33 volumio volumio[9697]: Updating browse sources language Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::initPlayerControls Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:33 volumio volumio[9697]: Express server listening on port 3000 Sep 05 06:00:33 volumio volumio[9697]: [Metrics] WebUI: 6s 139.85ms Sep 05 06:00:33 volumio volumio[9697]: info: CoreStateMachine::resetVolumioState Sep 05 06:00:33 volumio volumio[9697]: info: CoreStateMachine::getcurrentVolume Sep 05 06:00:33 volumio volumio[9697]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:34 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:34 volumio volumio[9697]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 05 06:00:34 volumio volumio[9697]: wlan0 Interface doesn't support scanning : Device or resource busy Sep 05 06:00:34 volumio volumio[9697]: info: Cannot use regular scanning, forcing with ap-force Sep 05 06:00:34 volumio sudo[9837]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 05 06:00:34 volumio sudo[9837]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:34 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:00:36 volumio sudo[9837]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:36 volumio volumio[9697]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Sep 05 06:00:36 volumio volumio[9697]: info: CoreStateMachine::pushState Sep 05 06:00:36 volumio volumio[9697]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:36 volumio volumio[9697]: info: CoreStateMachine::updateTrackBlock Sep 05 06:00:36 volumio volumio[9697]: info: CorePlayQueue::getTrackBlock Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:36 volumio volumio[9697]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 05 06:00:36 volumio volumio[9697]: info: CoreStateMachine::pushState Sep 05 06:00:36 volumio volumio[9697]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:36 volumio volumio[9697]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:00:36 volumio volumio[9697]: info: CoreStateMachine::pushState Sep 05 06:00:36 volumio volumio[9697]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:36 volumio volumio[9697]: info: CoreStateMachine::setRandom true Sep 05 06:00:36 volumio volumio[9697]: info: CoreStateMachine::pushState Sep 05 06:00:36 volumio volumio[9697]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:36 volumio volumio[9697]: info: Setting Device type: Raspberry PI Sep 05 06:00:36 volumio volumio[9697]: info: Completed loading Core Plugins Sep 05 06:00:36 volumio volumio[9697]: info: Preparing to generate the ALSA configuration file Sep 05 06:00:36 volumio volumio[9697]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:00:36 volumio volumio[9697]: info: Reading ALSA contributions from plugins. Sep 05 06:00:36 volumio volumio[9697]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:00:36 volumio volumio[9697]: info: Output device has changed, restarting MPD Sep 05 06:00:36 volumio sudo[9850]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:36 volumio sudo[9850]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:36 volumio sudo[9850]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:36 volumio volumio[9697]: info: ___________ START PLUGINS ___________ Sep 05 06:00:36 volumio volumio[9697]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:00:36 volumio volumio[9697]: info: Creating MPD Configuration file Sep 05 06:00:36 volumio sudo[9853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:36 volumio sudo[9853]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:36 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:00:36 volumio sudo[9856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:36 volumio volumio[9697]: info: [1725508836922] CoreMusicLibrary::Adding element Last_100 Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:36 volumio sudo[9856]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:36 volumio volumio[9697]: info: [1725508836933] CoreMusicLibrary::Adding element Webradio Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:36 volumio sudo[9856]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:36 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:36 volumio volumio[9697]: info: Initializing BBC Radios Sep 05 06:00:36 volumio sudo[9859]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:36 volumio sudo[9859]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:36 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:36 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:37 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:37 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:37 volumio volumio[9697]: info: AutoStart - onStart Sep 05 06:00:37 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:37 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 05 06:00:37 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:37 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:37 volumio volumio[9697]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:37 volumio volumio[9697]: info: [1725508837053] CoreMusicLibrary::Adding element LastFM Sep 05 06:00:37 volumio volumio[9697]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:37 volumio volumio[9697]: Cannot find translation for source LastFM Sep 05 06:00:37 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:37 volumio volumio[9697]: info: [LastFM] scrobbler initiated! Sep 05 06:00:37 volumio volumio[9697]: info: [LastFM] extended logging: false Sep 05 06:00:37 volumio volumio[9697]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:00:37 volumio volumio[9697]: info: [LastFM] Left init routine Sep 05 06:00:37 volumio volumio[9697]: info: [LastFM] Socket already connected: true Sep 05 06:00:37 volumio volumio[9697]: info: Volumio Calling Home Sep 05 06:00:37 volumio sudo[9872]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:00:37 volumio sudo[9872]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:37 volumio sudo[9872]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:37 volumio volumio[9697]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:37 volumio volumio[9697]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:00:37 volumio volumio[9697]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:00:37 volumio volumio[9697]: errno: -16, Sep 05 06:00:37 volumio volumio[9697]: code: 'EBUSY', Sep 05 06:00:37 volumio volumio[9697]: syscall: 'getaddrinfo', Sep 05 06:00:37 volumio volumio[9697]: hostname: 'ws.audioscrobbler.com' Sep 05 06:00:37 volumio volumio[9697]: } Sep 05 06:00:37 volumio volumio[9697]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:37 volumio sudo[9887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 05:59 Sep 05 06:00:37 volumio sudo[9887]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:38 volumio sudo[9887]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:38 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:00:38 volumio sudo[9853]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:38 volumio sudo[9859]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:38 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:00:38 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:38 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:38 volumio wpa_supplicant[849]: wlan0: Failed to initiate sched scan Sep 05 06:00:38 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:00:38 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8616. Sep 05 06:00:38 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:00:38 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:00:38 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:38 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:38 volumio mpd[9877]: Sep 05 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:00:39 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:00:39 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:00:40 volumio volumio[9900]: info: ------------------------------------------- Sep 05 06:00:40 volumio volumio[9900]: info: ----- Volumio3 ---- Sep 05 06:00:40 volumio volumio[9900]: info: ------------------------------------------- Sep 05 06:00:40 volumio volumio[9900]: info: ----- System startup ---- Sep 05 06:00:40 volumio volumio[9900]: info: ------------------------------------------- Sep 05 06:00:41 volumio volumio[9900]: info: MYVOLUMIO Environment detected Sep 05 06:00:41 volumio volumio[9900]: info: Plugin folders cleanup Sep 05 06:00:41 volumio volumio[9900]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category audio_interface Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category miscellanea Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category music_service Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category plugins.json Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category system_controller Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category user_interface Sep 05 06:00:41 volumio volumio[9900]: info: Scanning into folder /data/plugins/ Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category system_controller Sep 05 06:00:41 volumio volumio[9900]: info: Scanning category user_interface Sep 05 06:00:41 volumio volumio[9900]: info: Plugin folders cleanup completed Sep 05 06:00:41 volumio volumio[9900]: info: ------------------------------------------- Sep 05 06:00:41 volumio volumio[9900]: info: ----- Core plugins startup ---- Sep 05 06:00:41 volumio volumio[9900]: info: ------------------------------------------- Sep 05 06:00:41 volumio volumio[9900]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:00:41 volumio volumio[9900]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:00:41 volumio volumio[9900]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:00:41 volumio volumio[9900]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:00:41 volumio volumio[9900]: info: Loading plugins from folder /data/plugins/ Sep 05 06:00:41 volumio volumio[9900]: info: Loading plugin "system"... Sep 05 06:00:41 volumio volumio[9900]: info: Loading plugin "appearance"... Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "network"... Sep 05 06:00:42 volumio volumio[9900]: info: Refreshing Cached IP Addresses Sep 05 06:00:42 volumio sudo[9929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:00:42 volumio sudo[9929]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:42 volumio sudo[9929]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:42 volumio sudo[9931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "services"... Sep 05 06:00:42 volumio sudo[9931]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "alsa_controller"... Sep 05 06:00:42 volumio sudo[9931]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:42 volumio sudo[9934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:00:42 volumio sudo[9934]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:42 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "wizard"... Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "networkfs"... Sep 05 06:00:42 volumio volumio[9900]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:00:42 volumio volumio[9900]: info: Starting Udev Watcher for removable devices Sep 05 06:00:42 volumio volumio[9900]: info: Ignoring mount for partition: boot Sep 05 06:00:42 volumio volumio[9900]: info: Ignoring mount for partition: volumio Sep 05 06:00:42 volumio volumio[9900]: info: Ignoring mount for partition: volumio_data Sep 05 06:00:42 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:00:42 volumio volumio[9900]: info: Plugin upnp is not enabled Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "my_music"... Sep 05 06:00:42 volumio volumio[9900]: info: Loading plugin "mpd"... Sep 05 06:00:43 volumio volumio[9900]: info: Plugin upnp_browser is not enabled Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "alarm-clock"... Sep 05 06:00:43 volumio volumio[9900]: info: Plugin airplay_emulation is not enabled Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "last_100"... Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "webradio"... Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "i2s_dacs"... Sep 05 06:00:43 volumio volumio[9900]: info: I2S DAC not set, start Auto-detection Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "volumiodiscovery"... Sep 05 06:00:43 volumio volumio[9900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:43 volumio volumio[9900]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:43 volumio volumio[9900]: *** WARNING *** For more information see Sep 05 06:00:43 volumio volumio[9900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:43 volumio node[9900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:43 volumio volumio[9900]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:43 volumio volumio[9900]: *** WARNING *** For more information see Sep 05 06:00:43 volumio node[9900]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:43 volumio node[9900]: *** WARNING *** For more information see Sep 05 06:00:43 volumio node[9900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:43 volumio node[9900]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:43 volumio node[9900]: *** WARNING *** For more information see Sep 05 06:00:43 volumio volumio[9900]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:00:43 volumio volumio[9900]: info: Discovery: Started advertising with name: Volumio Sep 05 06:00:43 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "autostart"... Sep 05 06:00:43 volumio volumio-remote-updater[562]: [2024-09-05 06:00:43] [connect] Successful connection Sep 05 06:00:43 volumio ntpd[755]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Sep 05 06:00:43 volumio volumio[9900]: info: Applying required configuration parameters for plugin autostart Sep 05 06:00:43 volumio volumio[9900]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "outputs"... Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "albumart"... Sep 05 06:00:43 volumio volumio[9900]: info: Plugin example_plugin is not enabled Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "inputs"... Sep 05 06:00:43 volumio volumio[9900]: info: Loading plugin "updater_comm"... Sep 05 06:00:44 volumio volumio[9900]: info: Plugin mpdemulation is not enabled Sep 05 06:00:44 volumio volumio[9900]: info: Loading plugin "rest_api"... Sep 05 06:00:44 volumio volumio[9900]: info: Loading plugin "websocket"... Sep 05 06:00:44 volumio volumio[9900]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:00:44 volumio volumio[9900]: info: Loading plugin "backup_restore"... Sep 05 06:00:44 volumio volumio[9900]: Forking 3 albumart workers Sep 05 06:00:44 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:00:44 volumio volumio[9900]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:00:44 volumio volumio[9900]: info: Loading plugin "Systeminfo"... Sep 05 06:00:44 volumio volumio[9900]: info: Loading plugin "lastfm"... Sep 05 06:00:45 volumio volumio[9900]: Starting albumart workers Sep 05 06:00:45 volumio volumio[9900]: Starting albumart workers Sep 05 06:00:45 volumio volumio[9900]: Starting albumart workers Sep 05 06:00:45 volumio volumio[9900]: info: Loading plugin "randomizer"... Sep 05 06:00:46 volumio volumio[9900]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:00:46 volumio volumio[9900]: info: Loading i18n strings for locale en Sep 05 06:00:46 volumio volumio[9900]: Updating browse sources language Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::initPlayerControls Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:46 volumio volumio[9900]: Express server listening on port 3000 Sep 05 06:00:46 volumio volumio[9900]: [Metrics] WebUI: 6s 322.73ms Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::resetVolumioState Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::getcurrentVolume Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:46 volumio volumio-remote-updater[562]: [2024-09-05 06:00:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725508843 101 Sep 05 06:00:46 volumio volumio[9900]: 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 Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::pushState Sep 05 06:00:46 volumio volumio[9900]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::updateTrackBlock Sep 05 06:00:46 volumio volumio[9900]: info: CorePlayQueue::getTrackBlock Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:46 volumio volumio[9900]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::pushState Sep 05 06:00:46 volumio volumio[9900]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::pushState Sep 05 06:00:46 volumio volumio[9900]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::setRandom true Sep 05 06:00:46 volumio volumio[9900]: info: CoreStateMachine::pushState Sep 05 06:00:46 volumio volumio[9900]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:46 volumio volumio[9900]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:46 volumio volumio[9900]: info: Setting Device type: Raspberry PI Sep 05 06:00:46 volumio volumio[9900]: info: Completed loading Core Plugins Sep 05 06:00:46 volumio volumio[9900]: info: Preparing to generate the ALSA configuration file Sep 05 06:00:46 volumio volumio[9900]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:00:46 volumio volumio[9900]: info: Reading ALSA contributions from plugins. Sep 05 06:00:46 volumio volumio[9900]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:00:46 volumio volumio[9900]: info: Output device has changed, restarting MPD Sep 05 06:00:46 volumio sudo[10013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:46 volumio sudo[10013]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:46 volumio sudo[10013]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:46 volumio volumio[9900]: info: ___________ START PLUGINS ___________ Sep 05 06:00:46 volumio volumio[9900]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:00:46 volumio volumio[9900]: info: Creating MPD Configuration file Sep 05 06:00:46 volumio sudo[10016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:46 volumio sudo[10016]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:47 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:00:47 volumio sudo[10019]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:47 volumio sudo[10019]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:47 volumio sudo[10019]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:47 volumio volumio[9900]: info: [1725508847023] CoreMusicLibrary::Adding element Last_100 Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:47 volumio volumio[9900]: info: [1725508847035] CoreMusicLibrary::Adding element Webradio Sep 05 06:00:47 volumio sudo[10021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:47 volumio sudo[10021]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:47 volumio volumio[9900]: info: Initializing BBC Radios Sep 05 06:00:47 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:47 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:47 volumio wpa_supplicant[849]: wlan0: Failed to initiate sched scan Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:47 volumio volumio[9900]: info: AutoStart - onStart Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:47 volumio volumio[9900]: info: [1725508847152] CoreMusicLibrary::Adding element LastFM Sep 05 06:00:47 volumio volumio[9900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:47 volumio volumio[9900]: Cannot find translation for source LastFM Sep 05 06:00:47 volumio volumio[9900]: info: [LastFM] scrobbler initiated! Sep 05 06:00:47 volumio volumio[9900]: info: [LastFM] extended logging: false Sep 05 06:00:47 volumio volumio[9900]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:00:47 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:47 volumio volumio[9900]: info: [LastFM] Left init routine Sep 05 06:00:47 volumio volumio[9900]: info: [LastFM] Socket already connected: true Sep 05 06:00:47 volumio volumio[9900]: info: Volumio Calling Home Sep 05 06:00:47 volumio sudo[9934]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:47 volumio sudo[10026]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:00:47 volumio sudo[10026]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:47 volumio sudo[10026]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:47 volumio volumio[9900]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:47 volumio volumio[9900]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:00:47 volumio volumio[9900]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:00:47 volumio volumio[9900]: errno: -16, Sep 05 06:00:47 volumio volumio[9900]: code: 'EBUSY', Sep 05 06:00:47 volumio volumio[9900]: syscall: 'getaddrinfo', Sep 05 06:00:47 volumio volumio[9900]: hostname: 'ws.audioscrobbler.com' Sep 05 06:00:47 volumio volumio[9900]: } Sep 05 06:00:47 volumio volumio[9900]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:47 volumio ntpd[755]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 05 06:00:48 volumio sudo[10049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 05:59 Sep 05 06:00:48 volumio sudo[10049]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:48 volumio sudo[10049]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:48 volumio volumio-remote-updater[562]: [2024-09-05 06:00:48] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 05 06:00:48 volumio volumio-remote-updater[562]: [2024-09-05 06:00:48] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 05 06:00:48 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:00:48 volumio sudo[10016]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:48 volumio sudo[10021]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:48 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:00:48 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:48 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:48 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:00:48 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8617. Sep 05 06:00:48 volumio systemd[1]: Started dynamicswap service. Sep 05 06:00:48 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:00:48 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:00:48 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:00:48 volumio mpd[10039]: Sep 05 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:00:49 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:00:49 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:00:50 volumio volumio[10063]: info: ------------------------------------------- Sep 05 06:00:50 volumio volumio[10063]: info: ----- Volumio3 ---- Sep 05 06:00:50 volumio volumio[10063]: info: ------------------------------------------- Sep 05 06:00:50 volumio volumio[10063]: info: ----- System startup ---- Sep 05 06:00:50 volumio volumio[10063]: info: ------------------------------------------- Sep 05 06:00:51 volumio volumio[10063]: info: MYVOLUMIO Environment detected Sep 05 06:00:51 volumio volumio[10063]: info: Plugin folders cleanup Sep 05 06:00:51 volumio volumio[10063]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category audio_interface Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category miscellanea Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category music_service Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category plugins.json Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category system_controller Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category user_interface Sep 05 06:00:51 volumio volumio[10063]: info: Scanning into folder /data/plugins/ Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category system_controller Sep 05 06:00:51 volumio volumio[10063]: info: Scanning category user_interface Sep 05 06:00:51 volumio volumio[10063]: info: Plugin folders cleanup completed Sep 05 06:00:51 volumio volumio[10063]: info: ------------------------------------------- Sep 05 06:00:51 volumio volumio[10063]: info: ----- Core plugins startup ---- Sep 05 06:00:51 volumio volumio[10063]: info: ------------------------------------------- Sep 05 06:00:51 volumio volumio[10063]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:00:51 volumio volumio[10063]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:00:51 volumio volumio[10063]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:00:51 volumio volumio[10063]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:00:51 volumio volumio[10063]: info: Loading plugins from folder /data/plugins/ Sep 05 06:00:51 volumio volumio[10063]: info: Loading plugin "system"... Sep 05 06:00:51 volumio volumio[10063]: info: Loading plugin "appearance"... Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "network"... Sep 05 06:00:52 volumio volumio[10063]: info: Refreshing Cached IP Addresses Sep 05 06:00:52 volumio sudo[10091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:00:52 volumio sudo[10091]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:52 volumio sudo[10091]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "services"... Sep 05 06:00:52 volumio sudo[10093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:00:52 volumio sudo[10093]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:52 volumio sudo[10093]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "alsa_controller"... Sep 05 06:00:52 volumio sudo[10096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:00:52 volumio sudo[10096]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:52 volumio sudo[10096]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:52 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "wizard"... Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "networkfs"... Sep 05 06:00:52 volumio volumio[10063]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:00:52 volumio volumio[10063]: info: Starting Udev Watcher for removable devices Sep 05 06:00:52 volumio volumio[10063]: info: Ignoring mount for partition: boot Sep 05 06:00:52 volumio volumio[10063]: info: Ignoring mount for partition: volumio Sep 05 06:00:52 volumio volumio[10063]: info: Ignoring mount for partition: volumio_data Sep 05 06:00:52 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:00:52 volumio volumio[10063]: info: Plugin upnp is not enabled Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "my_music"... Sep 05 06:00:52 volumio volumio[10063]: info: Loading plugin "mpd"... Sep 05 06:00:53 volumio volumio[10063]: info: Plugin upnp_browser is not enabled Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "alarm-clock"... Sep 05 06:00:53 volumio volumio[10063]: info: Plugin airplay_emulation is not enabled Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "last_100"... Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "webradio"... Sep 05 06:00:53 volumio volumio-remote-updater[562]: [2024-09-05 06:00:53] [connect] Successful connection Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "i2s_dacs"... Sep 05 06:00:53 volumio volumio[10063]: info: I2S DAC not set, start Auto-detection Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "volumiodiscovery"... Sep 05 06:00:53 volumio volumio[10063]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:53 volumio volumio[10063]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:53 volumio volumio[10063]: *** WARNING *** For more information see Sep 05 06:00:53 volumio node[10063]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:53 volumio volumio[10063]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:53 volumio volumio[10063]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:53 volumio volumio[10063]: *** WARNING *** For more information see Sep 05 06:00:53 volumio node[10063]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:53 volumio node[10063]: *** WARNING *** For more information see Sep 05 06:00:53 volumio node[10063]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:00:53 volumio node[10063]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:00:53 volumio node[10063]: *** WARNING *** For more information see Sep 05 06:00:53 volumio volumio[10063]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:00:53 volumio volumio[10063]: info: Discovery: Started advertising with name: Volumio Sep 05 06:00:53 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "autostart"... Sep 05 06:00:53 volumio volumio[10063]: info: Applying required configuration parameters for plugin autostart Sep 05 06:00:53 volumio volumio[10063]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "outputs"... Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "albumart"... Sep 05 06:00:53 volumio volumio[10063]: info: Plugin example_plugin is not enabled Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "inputs"... Sep 05 06:00:53 volumio volumio[10063]: info: Loading plugin "updater_comm"... Sep 05 06:00:54 volumio volumio[10063]: info: Plugin mpdemulation is not enabled Sep 05 06:00:54 volumio volumio[10063]: info: Loading plugin "rest_api"... Sep 05 06:00:54 volumio volumio[10063]: info: Loading plugin "websocket"... Sep 05 06:00:54 volumio volumio[10063]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:00:54 volumio volumio[10063]: info: Loading plugin "backup_restore"... Sep 05 06:00:54 volumio volumio[10063]: Forking 3 albumart workers Sep 05 06:00:54 volumio wpa_supplicant[849]: wlan0: Failed to initiate sched scan Sep 05 06:00:54 volumio volumio[10063]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:00:54 volumio volumio[10063]: info: Loading plugin "Systeminfo"... Sep 05 06:00:54 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:00:54 volumio volumio[10063]: info: Loading plugin "lastfm"... Sep 05 06:00:55 volumio volumio[10063]: Starting albumart workers Sep 05 06:00:55 volumio volumio[10063]: info: Loading plugin "randomizer"... Sep 05 06:00:55 volumio volumio[10063]: Starting albumart workers Sep 05 06:00:55 volumio volumio[10063]: Starting albumart workers Sep 05 06:00:55 volumio volumio[10063]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:00:55 volumio volumio[10063]: info: Loading i18n strings for locale en Sep 05 06:00:55 volumio volumio[10063]: Updating browse sources language Sep 05 06:00:55 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::initPlayerControls Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: Express server listening on port 3000 Sep 05 06:00:56 volumio volumio[10063]: [Metrics] WebUI: 6s 133.33ms Sep 05 06:00:56 volumio volumio[10063]: info: CoreStateMachine::resetVolumioState Sep 05 06:00:56 volumio volumio[10063]: info: CoreStateMachine::getcurrentVolume Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:56 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:56 volumio volumio[10063]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 05 06:00:56 volumio volumio[10063]: wlan0 Interface doesn't support scanning : Device or resource busy Sep 05 06:00:56 volumio volumio[10063]: info: Cannot use regular scanning, forcing with ap-force Sep 05 06:00:56 volumio sudo[10165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 05 06:00:56 volumio sudo[10165]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:58 volumio sudo[10165]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:58 volumio volumio[10063]: info: Cannot mount NAS truenas at system boot, trial number 2 ,retrying in 5 seconds Sep 05 06:00:58 volumio volumio[10063]: info: CoreStateMachine::pushState Sep 05 06:00:58 volumio volumio[10063]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:58 volumio volumio[10063]: info: CoreStateMachine::updateTrackBlock Sep 05 06:00:58 volumio volumio[10063]: info: CorePlayQueue::getTrackBlock Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:00:58 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 05 06:00:58 volumio volumio[10063]: info: CoreStateMachine::pushState Sep 05 06:00:58 volumio volumio[10063]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:58 volumio volumio[10063]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:00:58 volumio volumio[10063]: info: CoreStateMachine::pushState Sep 05 06:00:58 volumio volumio[10063]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:58 volumio volumio[10063]: info: CoreStateMachine::setRandom true Sep 05 06:00:58 volumio volumio[10063]: info: CoreStateMachine::pushState Sep 05 06:00:58 volumio volumio[10063]: info: CorePlayQueue::getTrack 0 Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:00:58 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState Sep 05 06:00:58 volumio volumio[10063]: info: Setting Device type: Raspberry PI Sep 05 06:00:59 volumio volumio[10063]: info: Completed loading Core Plugins Sep 05 06:00:59 volumio volumio[10063]: info: Preparing to generate the ALSA configuration file Sep 05 06:00:59 volumio volumio[10063]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:00:59 volumio volumio[10063]: info: Reading ALSA contributions from plugins. Sep 05 06:00:59 volumio volumio[10063]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:00:59 volumio volumio[10063]: info: Output device has changed, restarting MPD Sep 05 06:00:59 volumio sudo[10178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:59 volumio sudo[10178]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:59 volumio sudo[10178]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:59 volumio volumio[10063]: info: ___________ START PLUGINS ___________ Sep 05 06:00:59 volumio volumio[10063]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:00:59 volumio volumio[10063]: info: Creating MPD Configuration file Sep 05 06:00:59 volumio sudo[10180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:59 volumio sudo[10180]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:59 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:00:59 volumio sudo[10184]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:00:59 volumio sudo[10184]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:59 volumio sudo[10184]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:59 volumio volumio[10063]: info: [1725508859199] CoreMusicLibrary::Adding element Last_100 Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:59 volumio volumio[10063]: info: [1725508859207] CoreMusicLibrary::Adding element Webradio Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:59 volumio sudo[10187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:00:59 volumio sudo[10187]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:59 volumio volumio[10063]: info: Initializing BBC Radios Sep 05 06:00:59 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:59 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:00:59 volumio volumio[10063]: info: AutoStart - onStart Sep 05 06:00:59 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:59 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 05 06:00:59 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:00:59 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:00:59 volumio volumio[10063]: info: [1725508859331] CoreMusicLibrary::Adding element LastFM Sep 05 06:00:59 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:00:59 volumio volumio[10063]: Cannot find translation for source LastFM Sep 05 06:00:59 volumio volumio[10063]: info: [LastFM] scrobbler initiated! Sep 05 06:00:59 volumio volumio[10063]: info: [LastFM] extended logging: false Sep 05 06:00:59 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:00:59 volumio volumio[10063]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:00:59 volumio volumio[10063]: info: [LastFM] Left init routine Sep 05 06:00:59 volumio volumio[10063]: info: [LastFM] Socket already connected: true Sep 05 06:00:59 volumio volumio[10063]: info: Volumio Calling Home Sep 05 06:00:59 volumio sudo[10200]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:00:59 volumio sudo[10200]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:00:59 volumio sudo[10200]: pam_unix(sudo:session): session closed for user root Sep 05 06:00:59 volumio volumio[10063]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:00:59 volumio volumio[10063]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:00:59 volumio volumio[10063]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:00:59 volumio volumio[10063]: errno: -16, Sep 05 06:00:59 volumio volumio[10063]: code: 'EBUSY', Sep 05 06:00:59 volumio volumio[10063]: syscall: 'getaddrinfo', Sep 05 06:00:59 volumio volumio[10063]: hostname: 'ws.audioscrobbler.com' Sep 05 06:00:59 volumio volumio[10063]: } Sep 05 06:00:59 volumio volumio[10063]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:01:00 volumio sudo[10216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 06:00 Sep 05 06:01:00 volumio sudo[10216]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:00 volumio sudo[10216]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:01:00 volumio sudo[10180]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:00 volumio sudo[10187]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:01:00 volumio systemd[1]: Started dynamicswap service. Sep 05 06:01:00 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:01:00 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:01:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8618. Sep 05 06:01:00 volumio systemd[1]: Started dynamicswap service. Sep 05 06:01:00 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:01:00 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:01:00 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:01:01 volumio mpd[10205]: Sep 05 06:01 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:01:01 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:01:01 volumio wpa_supplicant[849]: wlan0: Failed to initiate sched scan Sep 05 06:01:02 volumio volumio[10230]: info: ------------------------------------------- Sep 05 06:01:02 volumio volumio[10230]: info: ----- Volumio3 ---- Sep 05 06:01:02 volumio volumio[10230]: info: ------------------------------------------- Sep 05 06:01:02 volumio volumio[10230]: info: ----- System startup ---- Sep 05 06:01:02 volumio volumio[10230]: info: ------------------------------------------- Sep 05 06:01:03 volumio volumio[10230]: info: MYVOLUMIO Environment detected Sep 05 06:01:03 volumio volumio[10230]: info: Plugin folders cleanup Sep 05 06:01:03 volumio volumio[10230]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category audio_interface Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category miscellanea Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category music_service Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category plugins.json Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category system_controller Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category user_interface Sep 05 06:01:03 volumio volumio[10230]: info: Scanning into folder /data/plugins/ Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category system_controller Sep 05 06:01:03 volumio volumio[10230]: info: Scanning category user_interface Sep 05 06:01:03 volumio volumio[10230]: info: Plugin folders cleanup completed Sep 05 06:01:03 volumio volumio[10230]: info: ------------------------------------------- Sep 05 06:01:03 volumio volumio[10230]: info: ----- Core plugins startup ---- Sep 05 06:01:03 volumio volumio[10230]: info: ------------------------------------------- Sep 05 06:01:03 volumio volumio[10230]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:01:03 volumio volumio[10230]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:01:03 volumio volumio[10230]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:01:03 volumio volumio[10230]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:01:03 volumio volumio[10230]: info: Loading plugins from folder /data/plugins/ Sep 05 06:01:03 volumio volumio[10230]: info: Loading plugin "system"... Sep 05 06:01:03 volumio volumio[10230]: info: Loading plugin "appearance"... Sep 05 06:01:04 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:01:04 volumio volumio[10230]: info: Loading plugin "network"... Sep 05 06:01:04 volumio volumio[10230]: info: Refreshing Cached IP Addresses Sep 05 06:01:04 volumio sudo[10258]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:01:04 volumio sudo[10258]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:04 volumio sudo[10258]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:04 volumio volumio[10230]: info: Loading plugin "services"... Sep 05 06:01:04 volumio sudo[10260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:01:04 volumio sudo[10260]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:04 volumio volumio[10230]: info: Loading plugin "alsa_controller"... Sep 05 06:01:04 volumio sudo[10260]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:04 volumio sudo[10263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:01:04 volumio sudo[10263]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:04 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:04 volumio volumio[10230]: info: Loading plugin "wizard"... Sep 05 06:01:04 volumio volumio[10230]: info: Loading plugin "networkfs"... Sep 05 06:01:04 volumio volumio[10230]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:01:04 volumio volumio[10230]: info: Starting Udev Watcher for removable devices Sep 05 06:01:04 volumio volumio[10230]: info: Ignoring mount for partition: boot Sep 05 06:01:04 volumio volumio[10230]: info: Ignoring mount for partition: volumio Sep 05 06:01:04 volumio volumio[10230]: info: Ignoring mount for partition: volumio_data Sep 05 06:01:04 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:01:04 volumio volumio[10230]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:01:05 volumio volumio[10230]: info: Plugin upnp is not enabled Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "my_music"... Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "mpd"... Sep 05 06:01:05 volumio volumio[10230]: info: Plugin upnp_browser is not enabled Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "alarm-clock"... Sep 05 06:01:05 volumio volumio[10230]: info: Plugin airplay_emulation is not enabled Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "last_100"... Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "webradio"... Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "i2s_dacs"... Sep 05 06:01:05 volumio volumio[10230]: info: I2S DAC not set, start Auto-detection Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "volumiodiscovery"... Sep 05 06:01:05 volumio volumio[10230]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:05 volumio volumio[10230]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:05 volumio volumio[10230]: *** WARNING *** For more information see Sep 05 06:01:05 volumio node[10230]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:05 volumio volumio[10230]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:05 volumio volumio[10230]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:05 volumio volumio[10230]: *** WARNING *** For more information see Sep 05 06:01:05 volumio node[10230]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:05 volumio node[10230]: *** WARNING *** For more information see Sep 05 06:01:05 volumio node[10230]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:05 volumio node[10230]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:05 volumio node[10230]: *** WARNING *** For more information see Sep 05 06:01:05 volumio volumio[10230]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:01:05 volumio volumio[10230]: info: Discovery: Started advertising with name: Volumio Sep 05 06:01:05 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:01:05 volumio volumio[10230]: info: Loading plugin "autostart"... Sep 05 06:01:05 volumio volumio-remote-updater[562]: [2024-09-05 06:01:05] [connect] Successful connection Sep 05 06:01:06 volumio volumio[10230]: info: Applying required configuration parameters for plugin autostart Sep 05 06:01:06 volumio volumio[10230]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "outputs"... Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "albumart"... Sep 05 06:01:06 volumio volumio[10230]: info: Plugin example_plugin is not enabled Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "inputs"... Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "updater_comm"... Sep 05 06:01:06 volumio volumio[10230]: info: Plugin mpdemulation is not enabled Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "rest_api"... Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "websocket"... Sep 05 06:01:06 volumio volumio[10230]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "backup_restore"... Sep 05 06:01:06 volumio volumio[10230]: Forking 3 albumart workers Sep 05 06:01:06 volumio volumio[10230]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:01:06 volumio volumio[10230]: info: Loading plugin "Systeminfo"... Sep 05 06:01:07 volumio volumio[10230]: info: Loading plugin "lastfm"... Sep 05 06:01:07 volumio volumio[10230]: Starting albumart workers Sep 05 06:01:07 volumio volumio[10230]: Starting albumart workers Sep 05 06:01:07 volumio volumio[10230]: Starting albumart workers Sep 05 06:01:07 volumio volumio[10230]: info: Loading plugin "randomizer"... Sep 05 06:01:08 volumio volumio[10230]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:01:08 volumio volumio[10230]: info: Loading i18n strings for locale en Sep 05 06:01:08 volumio volumio[10230]: Updating browse sources language Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::initPlayerControls Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:01:08 volumio volumio[10230]: Express server listening on port 3000 Sep 05 06:01:08 volumio volumio[10230]: [Metrics] WebUI: 6s 339.08ms Sep 05 06:01:08 volumio volumio[10230]: info: CoreStateMachine::resetVolumioState Sep 05 06:01:08 volumio volumio[10230]: info: CoreStateMachine::getcurrentVolume Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:01:08 volumio volumio-remote-updater[562]: [2024-09-05 06:01:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725508865 101 Sep 05 06:01:08 volumio volumio[10230]: 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 Sep 05 06:01:08 volumio volumio[10230]: info: CoreStateMachine::pushState Sep 05 06:01:08 volumio volumio[10230]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:08 volumio volumio[10230]: info: CoreStateMachine::updateTrackBlock Sep 05 06:01:08 volumio volumio[10230]: info: CorePlayQueue::getTrackBlock Sep 05 06:01:08 volumio volumio[10230]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:01:08 volumio volumio[10230]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 05 06:01:09 volumio volumio[10230]: info: CoreStateMachine::pushState Sep 05 06:01:09 volumio volumio[10230]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:09 volumio volumio[10230]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:01:09 volumio volumio[10230]: info: CoreStateMachine::pushState Sep 05 06:01:09 volumio volumio[10230]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:09 volumio volumio[10230]: info: CoreStateMachine::setRandom true Sep 05 06:01:09 volumio volumio[10230]: info: CoreStateMachine::pushState Sep 05 06:01:09 volumio volumio[10230]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:09 volumio volumio[10230]: info: Setting Device type: Raspberry PI Sep 05 06:01:09 volumio volumio[10230]: info: Completed loading Core Plugins Sep 05 06:01:09 volumio volumio[10230]: info: Preparing to generate the ALSA configuration file Sep 05 06:01:09 volumio volumio[10230]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:01:09 volumio volumio[10230]: info: Reading ALSA contributions from plugins. Sep 05 06:01:09 volumio volumio[10230]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:01:09 volumio volumio[10230]: info: Output device has changed, restarting MPD Sep 05 06:01:09 volumio sudo[10342]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:01:09 volumio sudo[10342]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:09 volumio volumio[10230]: info: ___________ START PLUGINS ___________ Sep 05 06:01:09 volumio sudo[10342]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:09 volumio volumio[10230]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:01:09 volumio volumio[10230]: info: Creating MPD Configuration file Sep 05 06:01:09 volumio sudo[10344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:01:09 volumio sudo[10344]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:09 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:09 volumio volumio[10230]: info: [1725508869238] CoreMusicLibrary::Adding element Last_100 Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:09 volumio sudo[10348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:09 volumio volumio[10230]: info: [1725508869248] CoreMusicLibrary::Adding element Webradio Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:09 volumio sudo[10348]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:09 volumio volumio[10230]: info: Initializing BBC Radios Sep 05 06:01:09 volumio sudo[10350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:01:09 volumio sudo[10350]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:09 volumio sudo[10348]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:09 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:01:09 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:01:09 volumio volumio[10230]: info: AutoStart - onStart Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:09 volumio volumio[10230]: info: [1725508869369] CoreMusicLibrary::Adding element LastFM Sep 05 06:01:09 volumio volumio[10230]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:09 volumio volumio[10230]: Cannot find translation for source LastFM Sep 05 06:01:09 volumio volumio[10230]: info: [LastFM] scrobbler initiated! Sep 05 06:01:09 volumio volumio[10230]: info: [LastFM] extended logging: false Sep 05 06:01:09 volumio volumio[10230]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:01:09 volumio wpa_supplicant[849]: wlan0: Failed to initiate sched scan Sep 05 06:01:09 volumio volumio[10230]: info: [LastFM] Left init routine Sep 05 06:01:09 volumio volumio[10230]: info: [LastFM] Socket already connected: true Sep 05 06:01:09 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:01:09 volumio volumio[10230]: info: Volumio Calling Home Sep 05 06:01:09 volumio sudo[10263]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:09 volumio sudo[10356]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:01:09 volumio sudo[10356]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:09 volumio sudo[10356]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:09 volumio volumio[10230]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:01:09 volumio volumio[10230]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:01:09 volumio volumio[10230]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:01:09 volumio volumio[10230]: errno: -16, Sep 05 06:01:09 volumio volumio[10230]: code: 'EBUSY', Sep 05 06:01:09 volumio volumio[10230]: syscall: 'getaddrinfo', Sep 05 06:01:09 volumio volumio[10230]: hostname: 'ws.audioscrobbler.com' Sep 05 06:01:09 volumio volumio[10230]: } Sep 05 06:01:09 volumio volumio[10230]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:01:09 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:01:10 volumio sudo[10378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 06:00 Sep 05 06:01:10 volumio sudo[10378]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:10 volumio sudo[10378]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:10 volumio volumio-remote-updater[562]: [2024-09-05 06:01:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 05 06:01:10 volumio volumio-remote-updater[562]: [2024-09-05 06:01:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 05 06:01:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:01:10 volumio sudo[10350]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:10 volumio sudo[10344]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:01:10 volumio systemd[1]: Started dynamicswap service. Sep 05 06:01:10 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:01:10 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:01:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8619. Sep 05 06:01:10 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:01:10 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:01:10 volumio systemd[1]: Started dynamicswap service. Sep 05 06:01:10 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:01:11 volumio mpd[10368]: Sep 05 06:01 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:01:11 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:01:12 volumio volumio[10391]: info: ------------------------------------------- Sep 05 06:01:12 volumio volumio[10391]: info: ----- Volumio3 ---- Sep 05 06:01:12 volumio volumio[10391]: info: ------------------------------------------- Sep 05 06:01:12 volumio volumio[10391]: info: ----- System startup ---- Sep 05 06:01:12 volumio volumio[10391]: info: ------------------------------------------- Sep 05 06:01:13 volumio volumio[10391]: info: MYVOLUMIO Environment detected Sep 05 06:01:13 volumio volumio[10391]: info: Plugin folders cleanup Sep 05 06:01:13 volumio volumio[10391]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category audio_interface Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category miscellanea Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category music_service Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category plugins.json Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category system_controller Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category user_interface Sep 05 06:01:13 volumio volumio[10391]: info: Scanning into folder /data/plugins/ Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category system_controller Sep 05 06:01:13 volumio volumio[10391]: info: Scanning category user_interface Sep 05 06:01:13 volumio volumio[10391]: info: Plugin folders cleanup completed Sep 05 06:01:13 volumio volumio[10391]: info: ------------------------------------------- Sep 05 06:01:13 volumio volumio[10391]: info: ----- Core plugins startup ---- Sep 05 06:01:13 volumio volumio[10391]: info: ------------------------------------------- Sep 05 06:01:13 volumio volumio[10391]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:01:13 volumio volumio[10391]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:01:13 volumio volumio[10391]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:01:13 volumio volumio[10391]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:01:13 volumio volumio[10391]: info: Loading plugins from folder /data/plugins/ Sep 05 06:01:13 volumio volumio[10391]: info: Loading plugin "system"... Sep 05 06:01:13 volumio volumio[10391]: info: Loading plugin "appearance"... Sep 05 06:01:14 volumio volumio[10391]: info: Loading plugin "network"... Sep 05 06:01:14 volumio volumio[10391]: info: Refreshing Cached IP Addresses Sep 05 06:01:14 volumio sudo[10420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:01:14 volumio sudo[10420]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:14 volumio sudo[10420]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:14 volumio sudo[10422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:01:14 volumio volumio[10391]: info: Loading plugin "services"... Sep 05 06:01:14 volumio sudo[10422]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:14 volumio volumio[10391]: info: Loading plugin "alsa_controller"... Sep 05 06:01:14 volumio sudo[10422]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:14 volumio sudo[10425]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:01:14 volumio sudo[10425]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:14 volumio sudo[10425]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:14 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:14 volumio volumio[10391]: info: Loading plugin "wizard"... Sep 05 06:01:14 volumio volumio[10391]: info: Loading plugin "networkfs"... Sep 05 06:01:14 volumio volumio[10391]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:01:14 volumio volumio[10391]: info: Starting Udev Watcher for removable devices Sep 05 06:01:15 volumio volumio[10391]: info: Ignoring mount for partition: boot Sep 05 06:01:15 volumio volumio[10391]: info: Ignoring mount for partition: volumio Sep 05 06:01:15 volumio volumio[10391]: info: Ignoring mount for partition: volumio_data Sep 05 06:01:15 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:01:15 volumio volumio[10391]: info: Plugin upnp is not enabled Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "my_music"... Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "mpd"... Sep 05 06:01:15 volumio volumio[10391]: info: Plugin upnp_browser is not enabled Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "alarm-clock"... Sep 05 06:01:15 volumio volumio-remote-updater[562]: [2024-09-05 06:01:15] [connect] Successful connection Sep 05 06:01:15 volumio volumio[10391]: info: Plugin airplay_emulation is not enabled Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "last_100"... Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "webradio"... Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "i2s_dacs"... Sep 05 06:01:15 volumio volumio[10391]: info: I2S DAC not set, start Auto-detection Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "volumiodiscovery"... Sep 05 06:01:15 volumio volumio[10391]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:15 volumio volumio[10391]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:15 volumio volumio[10391]: *** WARNING *** For more information see Sep 05 06:01:15 volumio node[10391]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:15 volumio volumio[10391]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:15 volumio volumio[10391]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:15 volumio volumio[10391]: *** WARNING *** For more information see Sep 05 06:01:15 volumio node[10391]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:15 volumio node[10391]: *** WARNING *** For more information see Sep 05 06:01:15 volumio node[10391]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:15 volumio node[10391]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:15 volumio node[10391]: *** WARNING *** For more information see Sep 05 06:01:15 volumio volumio[10391]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:01:15 volumio volumio[10391]: info: Discovery: Started advertising with name: Volumio Sep 05 06:01:15 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:01:15 volumio volumio[10391]: info: Loading plugin "autostart"... Sep 05 06:01:16 volumio volumio[10391]: info: Applying required configuration parameters for plugin autostart Sep 05 06:01:16 volumio volumio[10391]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "outputs"... Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "albumart"... Sep 05 06:01:16 volumio volumio[10391]: info: Plugin example_plugin is not enabled Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "inputs"... Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "updater_comm"... Sep 05 06:01:16 volumio volumio[10391]: info: Plugin mpdemulation is not enabled Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "rest_api"... Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "websocket"... Sep 05 06:01:16 volumio volumio[10391]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "backup_restore"... Sep 05 06:01:16 volumio ntpd[755]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 05 06:01:16 volumio volumio[10391]: Forking 3 albumart workers Sep 05 06:01:16 volumio wpa_supplicant[849]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="Hoi" Sep 05 06:01:16 volumio wpa_supplicant[849]: wlan0: Trying to associate with SSID 'Hoi' Sep 05 06:01:16 volumio volumio[10391]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:01:16 volumio volumio[10391]: info: Loading plugin "Systeminfo"... Sep 05 06:01:17 volumio volumio[10391]: info: Loading plugin "lastfm"... Sep 05 06:01:17 volumio volumio[10391]: Starting albumart workers Sep 05 06:01:17 volumio volumio[10391]: Starting albumart workers Sep 05 06:01:17 volumio volumio[10391]: Starting albumart workers Sep 05 06:01:17 volumio volumio[10391]: info: Loading plugin "randomizer"... Sep 05 06:01:18 volumio volumio[10391]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:01:18 volumio volumio[10391]: info: Loading i18n strings for locale en Sep 05 06:01:18 volumio volumio[10391]: Updating browse sources language Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::initPlayerControls Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: Express server listening on port 3000 Sep 05 06:01:18 volumio volumio[10391]: [Metrics] WebUI: 6s 240.79ms Sep 05 06:01:18 volumio volumio[10391]: info: CoreStateMachine::resetVolumioState Sep 05 06:01:18 volumio volumio[10391]: info: CoreStateMachine::getcurrentVolume Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:01:18 volumio volumio[10391]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 05 06:01:18 volumio volumio[10391]: wlan0 Interface doesn't support scanning : Device or resource busy Sep 05 06:01:18 volumio volumio[10391]: info: Cannot use regular scanning, forcing with ap-force Sep 05 06:01:18 volumio sudo[10494]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 05 06:01:18 volumio sudo[10494]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:18 volumio sudo[10494]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:18 volumio volumio[10391]: command failed: Resource temporarily unavailable (-11) Sep 05 06:01:18 volumio volumio[10391]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 05 06:01:18 volumio volumio[10391]: command failed: Resource temporarily unavailable (-11) Sep 05 06:01:18 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3) Sep 05 06:01:18 volumio volumio-remote-updater[562]: [2024-09-05 06:01:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725508875 101 Sep 05 06:01:18 volumio volumio[10391]: 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 Sep 05 06:01:18 volumio volumio[10391]: info: CoreStateMachine::pushState Sep 05 06:01:18 volumio volumio[10391]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:18 volumio volumio[10391]: info: CoreStateMachine::updateTrackBlock Sep 05 06:01:18 volumio volumio[10391]: info: CorePlayQueue::getTrackBlock Sep 05 06:01:18 volumio volumio[10391]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:01:18 volumio volumio[10391]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 05 06:01:19 volumio volumio[10391]: info: CoreStateMachine::pushState Sep 05 06:01:19 volumio volumio[10391]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:19 volumio volumio[10391]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:01:19 volumio volumio[10391]: info: CoreStateMachine::pushState Sep 05 06:01:19 volumio volumio[10391]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:19 volumio volumio[10391]: info: CoreStateMachine::setRandom true Sep 05 06:01:19 volumio volumio[10391]: info: CoreStateMachine::pushState Sep 05 06:01:19 volumio volumio[10391]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:19 volumio volumio[10391]: info: Setting Device type: Raspberry PI Sep 05 06:01:19 volumio dhcpcd[861]: wlan0: carrier acquired Sep 05 06:01:19 volumio wpa_supplicant[849]: wlan0: Associated with 38:a6:59:ba:aa:ea Sep 05 06:01:19 volumio wpa_supplicant[849]: wlan0: CTRL-EVENT-CONNECTED - Connection to 38:a6:59:ba:aa:ea completed [id=0 id_str=] Sep 05 06:01:19 volumio wpa_supplicant[849]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Sep 05 06:01:19 volumio wpa_supplicant[849]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=NL Sep 05 06:01:19 volumio dhcpcd[861]: wlan0: IAID eb:e1:35:17 Sep 05 06:01:19 volumio dhcpcd[861]: wlan0: carrier lost Sep 05 06:01:19 volumio dhcpcd[861]: wlan0: carrier acquired Sep 05 06:01:19 volumio dhcpcd[861]: wlan0: IAID eb:e1:35:17 Sep 05 06:01:19 volumio volumio[10391]: info: Completed loading Core Plugins Sep 05 06:01:19 volumio volumio[10391]: info: Preparing to generate the ALSA configuration file Sep 05 06:01:19 volumio volumio[10391]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:01:19 volumio volumio[10391]: info: Reading ALSA contributions from plugins. Sep 05 06:01:19 volumio volumio[10391]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:01:19 volumio volumio[10391]: info: Output device has changed, restarting MPD Sep 05 06:01:19 volumio sudo[10519]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:01:19 volumio sudo[10519]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:19 volumio volumio[10391]: info: ___________ START PLUGINS ___________ Sep 05 06:01:19 volumio sudo[10519]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:19 volumio volumio[10391]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:01:19 volumio volumio[10391]: info: Creating MPD Configuration file Sep 05 06:01:19 volumio sudo[10521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:01:19 volumio sudo[10521]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:19 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:01:19 volumio sudo[10525]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:01:19 volumio sudo[10525]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:19 volumio volumio[10391]: info: [1725508879272] CoreMusicLibrary::Adding element Last_100 Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:19 volumio sudo[10525]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:19 volumio volumio[10391]: info: [1725508879285] CoreMusicLibrary::Adding element Webradio Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:19 volumio sudo[10528]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:01:19 volumio sudo[10528]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:19 volumio volumio[10391]: info: Initializing BBC Radios Sep 05 06:01:19 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:01:19 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:19 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:01:19 volumio volumio[10391]: info: AutoStart - onStart Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:19 volumio volumio[10391]: info: [1725508879404] CoreMusicLibrary::Adding element LastFM Sep 05 06:01:19 volumio volumio[10391]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:19 volumio volumio[10391]: Cannot find translation for source LastFM Sep 05 06:01:19 volumio volumio[10391]: info: [LastFM] scrobbler initiated! Sep 05 06:01:19 volumio volumio[10391]: info: [LastFM] extended logging: false Sep 05 06:01:19 volumio volumio[10391]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:01:19 volumio volumio[10391]: info: [LastFM] Left init routine Sep 05 06:01:19 volumio volumio[10391]: info: [LastFM] Socket already connected: true Sep 05 06:01:19 volumio volumio[10391]: info: Volumio Calling Home Sep 05 06:01:19 volumio dhcpcd[861]: wlan0: soliciting an IPv6 router Sep 05 06:01:19 volumio sudo[10532]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:01:19 volumio sudo[10532]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:19 volumio sudo[10532]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:19 volumio volumio[10391]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:01:19 volumio volumio[10391]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:01:19 volumio volumio[10391]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:01:19 volumio volumio[10391]: errno: -16, Sep 05 06:01:19 volumio volumio[10391]: code: 'EBUSY', Sep 05 06:01:19 volumio volumio[10391]: syscall: 'getaddrinfo', Sep 05 06:01:19 volumio volumio[10391]: hostname: 'ws.audioscrobbler.com' Sep 05 06:01:19 volumio volumio[10391]: } Sep 05 06:01:19 volumio volumio[10391]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:01:19 volumio dhcpcd[861]: wlan0: soliciting a DHCP lease Sep 05 06:01:19 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:01:20 volumio sudo[10555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 06:00 Sep 05 06:01:20 volumio sudo[10555]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:20 volumio sudo[10555]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:20 volumio volumio-remote-updater[562]: [2024-09-05 06:01:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 05 06:01:20 volumio volumio-remote-updater[562]: [2024-09-05 06:01:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 05 06:01:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 05 06:01:20 volumio sudo[10521]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:20 volumio sudo[10528]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 05 06:01:20 volumio systemd[1]: Started dynamicswap service. Sep 05 06:01:20 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:01:20 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 05 06:01:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8620. Sep 05 06:01:20 volumio systemd[1]: Started dynamicswap service. Sep 05 06:01:20 volumio systemd[1]: Stopped Volumio Backend Module. Sep 05 06:01:20 volumio systemd[1]: Started Volumio Backend Module. Sep 05 06:01:21 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 05 06:01:21 volumio mpd[10545]: Sep 05 06:01 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 05 06:01:21 volumio systemd[1]: Started Music Player Daemon. Sep 05 06:01:22 volumio volumio[10570]: info: ------------------------------------------- Sep 05 06:01:22 volumio volumio[10570]: info: ----- Volumio3 ---- Sep 05 06:01:22 volumio volumio[10570]: info: ------------------------------------------- Sep 05 06:01:22 volumio volumio[10570]: info: ----- System startup ---- Sep 05 06:01:22 volumio volumio[10570]: info: ------------------------------------------- Sep 05 06:01:23 volumio volumio[10570]: info: MYVOLUMIO Environment detected Sep 05 06:01:23 volumio volumio[10570]: info: Plugin folders cleanup Sep 05 06:01:23 volumio volumio[10570]: info: Scanning into folder /volumio/app/plugins/ Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category audio_interface Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category miscellanea Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category music_service Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category plugins.json Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category system_controller Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category user_interface Sep 05 06:01:23 volumio volumio[10570]: info: Scanning into folder /data/plugins/ Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category system_controller Sep 05 06:01:23 volumio volumio[10570]: info: Scanning category user_interface Sep 05 06:01:23 volumio volumio[10570]: info: Plugin folders cleanup completed Sep 05 06:01:23 volumio volumio[10570]: info: ------------------------------------------- Sep 05 06:01:23 volumio volumio[10570]: info: ----- Core plugins startup ---- Sep 05 06:01:23 volumio volumio[10570]: info: ------------------------------------------- Sep 05 06:01:23 volumio volumio[10570]: info: Loading plugins from folder /volumio/app/plugins/ Sep 05 06:01:23 volumio volumio[10570]: info: Adding plugin upnp to MyMusic Plugins Sep 05 06:01:23 volumio volumio[10570]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 05 06:01:23 volumio volumio[10570]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 05 06:01:23 volumio volumio[10570]: info: Loading plugins from folder /data/plugins/ Sep 05 06:01:23 volumio volumio[10570]: info: Loading plugin "system"... Sep 05 06:01:23 volumio volumio[10570]: info: Loading plugin "appearance"... Sep 05 06:01:24 volumio dhcpcd[861]: wlan0: offered 192.168.2.6 from 192.168.2.254 `mijnmodem' Sep 05 06:01:24 volumio dhcpcd[861]: wlan0: probing address 192.168.2.6/24 Sep 05 06:01:24 volumio volumio[10570]: info: Loading plugin "network"... Sep 05 06:01:24 volumio volumio[10570]: info: Refreshing Cached IP Addresses Sep 05 06:01:24 volumio sudo[10599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 05 06:01:24 volumio sudo[10599]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:24 volumio sudo[10599]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:24 volumio sudo[10601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 05 06:01:24 volumio volumio[10570]: info: Loading plugin "services"... Sep 05 06:01:24 volumio sudo[10601]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:24 volumio volumio[10570]: info: Loading plugin "alsa_controller"... Sep 05 06:01:24 volumio sudo[10601]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:24 volumio sudo[10604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 05 06:01:24 volumio sudo[10604]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:24 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:24 volumio volumio[10570]: info: Loading plugin "wizard"... Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "networkfs"... Sep 05 06:01:25 volumio volumio[10570]: info: Cannot mount NAS truenas at system boot, trial number 1 ,retrying in 5 seconds Sep 05 06:01:25 volumio volumio[10570]: info: Starting Udev Watcher for removable devices Sep 05 06:01:25 volumio volumio[10570]: info: Ignoring mount for partition: boot Sep 05 06:01:25 volumio volumio[10570]: info: Ignoring mount for partition: volumio Sep 05 06:01:25 volumio volumio[10570]: info: Ignoring mount for partition: volumio_data Sep 05 06:01:25 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "volumio_command_line_client"... Sep 05 06:01:25 volumio volumio[10570]: info: Plugin upnp is not enabled Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "my_music"... Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "mpd"... Sep 05 06:01:25 volumio volumio[10570]: info: Plugin upnp_browser is not enabled Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "alarm-clock"... Sep 05 06:01:25 volumio ntpd[755]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 05 06:01:25 volumio volumio[10570]: info: Plugin airplay_emulation is not enabled Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "last_100"... Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "webradio"... Sep 05 06:01:25 volumio volumio-remote-updater[562]: [2024-09-05 06:01:25] [connect] Successful connection Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "i2s_dacs"... Sep 05 06:01:25 volumio volumio[10570]: info: I2S DAC not set, start Auto-detection Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "volumiodiscovery"... Sep 05 06:01:25 volumio volumio[10570]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:25 volumio volumio[10570]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:25 volumio node[10570]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:25 volumio volumio[10570]: *** WARNING *** For more information see Sep 05 06:01:25 volumio volumio[10570]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:25 volumio volumio[10570]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:25 volumio volumio[10570]: *** WARNING *** For more information see Sep 05 06:01:25 volumio node[10570]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:25 volumio node[10570]: *** WARNING *** For more information see Sep 05 06:01:25 volumio node[10570]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 05 06:01:25 volumio node[10570]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 05 06:01:25 volumio node[10570]: *** WARNING *** For more information see Sep 05 06:01:25 volumio volumio[10570]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 05 06:01:25 volumio volumio[10570]: info: Discovery: Started advertising with name: Volumio Sep 05 06:01:25 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 05 06:01:25 volumio volumio[10570]: info: Loading plugin "autostart"... Sep 05 06:01:26 volumio volumio[10570]: info: Applying required configuration parameters for plugin autostart Sep 05 06:01:26 volumio volumio[10570]: info: AutoStart - onVolumioStart - read config.json Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "outputs"... Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "albumart"... Sep 05 06:01:26 volumio volumio[10570]: info: Plugin example_plugin is not enabled Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "inputs"... Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "updater_comm"... Sep 05 06:01:26 volumio volumio[10570]: info: Plugin mpdemulation is not enabled Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "rest_api"... Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "websocket"... Sep 05 06:01:26 volumio volumio[10570]: info: Starting Socket.io Server version 2.3.0 Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "backup_restore"... Sep 05 06:01:26 volumio volumio[10570]: Forking 3 albumart workers Sep 05 06:01:26 volumio volumio[10570]: info: Applying required configuration parameters for plugin backup_restore Sep 05 06:01:26 volumio volumio[10570]: info: Loading plugin "Systeminfo"... Sep 05 06:01:27 volumio volumio[10570]: info: Loading plugin "lastfm"... Sep 05 06:01:27 volumio volumio[10570]: Starting albumart workers Sep 05 06:01:27 volumio volumio[10570]: Starting albumart workers Sep 05 06:01:27 volumio volumio[10570]: Starting albumart workers Sep 05 06:01:27 volumio volumio[10570]: info: Loading plugin "randomizer"... Sep 05 06:01:28 volumio sudo[10604]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:28 volumio volumio[10570]: info: Applying required configuration parameters for plugin randomizer Sep 05 06:01:28 volumio volumio[10570]: info: Loading i18n strings for locale en Sep 05 06:01:28 volumio volumio[10570]: Updating browse sources language Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::initPlayerControls Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 05 06:01:28 volumio volumio[10570]: Express server listening on port 3000 Sep 05 06:01:28 volumio volumio[10570]: [Metrics] WebUI: 6s 321.11ms Sep 05 06:01:28 volumio volumio[10570]: info: CoreStateMachine::resetVolumioState Sep 05 06:01:28 volumio volumio[10570]: info: CoreStateMachine::getcurrentVolume Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:01:28 volumio volumio-remote-updater[562]: [2024-09-05 06:01:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725508885 101 Sep 05 06:01:28 volumio volumio[10570]: 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 Sep 05 06:01:28 volumio volumio[10570]: info: CoreStateMachine::pushState Sep 05 06:01:28 volumio volumio[10570]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:28 volumio volumio[10570]: info: CoreStateMachine::updateTrackBlock Sep 05 06:01:28 volumio volumio[10570]: info: CorePlayQueue::getTrackBlock Sep 05 06:01:28 volumio volumio[10570]: info: CoreCommandRouter::volumioRetrievevolume Sep 05 06:01:28 volumio volumio[10570]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 05 06:01:29 volumio volumio[10570]: info: CoreStateMachine::pushState Sep 05 06:01:29 volumio volumio[10570]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:29 volumio volumio[10570]: info: CoreStateMachine::setRepeat true single undefined Sep 05 06:01:29 volumio volumio[10570]: info: CoreStateMachine::pushState Sep 05 06:01:29 volumio volumio[10570]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:29 volumio volumio[10570]: info: CoreStateMachine::setRandom true Sep 05 06:01:29 volumio volumio[10570]: info: CoreStateMachine::pushState Sep 05 06:01:29 volumio volumio[10570]: info: CorePlayQueue::getTrack 0 Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::volumioPushState Sep 05 06:01:29 volumio volumio[10570]: info: Setting Device type: Raspberry PI Sep 05 06:01:29 volumio volumio[10570]: info: Completed loading Core Plugins Sep 05 06:01:29 volumio volumio[10570]: info: Preparing to generate the ALSA configuration file Sep 05 06:01:29 volumio volumio[10570]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 05 06:01:29 volumio volumio[10570]: info: Reading ALSA contributions from plugins. Sep 05 06:01:29 volumio volumio[10570]: info: Asound.conf file unchanged, so no further update is needed Sep 05 06:01:29 volumio volumio[10570]: info: Output device has changed, restarting MPD Sep 05 06:01:29 volumio sudo[10683]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:01:29 volumio sudo[10683]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:29 volumio volumio[10570]: info: ___________ START PLUGINS ___________ Sep 05 06:01:29 volumio sudo[10683]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:29 volumio volumio[10570]: info: ControllerMpd::onStart: Initializing MPD Sep 05 06:01:29 volumio volumio[10570]: info: Creating MPD Configuration file Sep 05 06:01:29 volumio sudo[10685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:01:29 volumio sudo[10685]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:29 volumio sudo[10689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 05 06:01:29 volumio systemd[1]: Stopping Music Player Daemon... Sep 05 06:01:29 volumio sudo[10689]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:29 volumio sudo[10689]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:29 volumio volumio[10570]: info: [1725508889298] CoreMusicLibrary::Adding element Last_100 Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:29 volumio volumio[10570]: info: [1725508889308] CoreMusicLibrary::Adding element Webradio Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:29 volumio sudo[10692]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 05 06:01:29 volumio sudo[10692]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:29 volumio volumio[10570]: info: Initializing BBC Radios Sep 05 06:01:29 volumio systemd[1]: mpd.service: Succeeded. Sep 05 06:01:29 volumio systemd[1]: Stopped Music Player Daemon. Sep 05 06:01:29 volumio systemd[1]: Starting Music Player Daemon... Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 05 06:01:29 volumio volumio[10570]: info: AutoStart - onStart Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 05 06:01:29 volumio volumio[10570]: info: [1725508889444] CoreMusicLibrary::Adding element LastFM Sep 05 06:01:29 volumio volumio[10570]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 05 06:01:29 volumio volumio[10570]: Cannot find translation for source LastFM Sep 05 06:01:29 volumio volumio[10570]: info: [LastFM] scrobbler initiated! Sep 05 06:01:29 volumio volumio[10570]: info: [LastFM] extended logging: false Sep 05 06:01:29 volumio volumio[10570]: info: [LastFM] try scrobble stream/radio plays: true Sep 05 06:01:29 volumio volumio[10570]: info: [LastFM] Left init routine Sep 05 06:01:29 volumio volumio[10570]: info: [LastFM] Socket already connected: true Sep 05 06:01:29 volumio volumio[10570]: info: Volumio Calling Home Sep 05 06:01:29 volumio sudo[10695]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 05 06:01:29 volumio sudo[10695]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 05 06:01:29 volumio sudo[10695]: pam_unix(sudo:session): session closed for user root Sep 05 06:01:29 volumio volumio[10570]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:01:29 volumio volumio[10570]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Sep 05 06:01:29 volumio volumio[10570]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Sep 05 06:01:29 volumio volumio[10570]: errno: -16, Sep 05 06:01:29 volumio volumio[10570]: code: 'EBUSY', Sep 05 06:01:29 volumio volumio[10570]: syscall: 'getaddrinfo', Sep 05 06:01:29 volumio volumio[10570]: hostname: 'ws.audioscrobbler.com' Sep 05 06:01:29 volumio volumio[10570]: } Sep 05 06:01:29 volumio volumio[10570]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 06:01:29 volumio dhcpcd[861]: wlan0: leased 192.168.2.6 for 86400 seconds Sep 05 06:01:29 volumio avahi-daemon[572]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.6. Sep 05 06:01:29 volumio dhcpcd[861]: wlan0: adding route to 192.168.2.0/24 Sep 05 06:01:29 volumio dhcpcd[861]: wlan0: adding default route via 192.168.2.254 Sep 05 06:01:29 volumio kernel: nfs: server 192.168.2.29 not responding, timed out Sep 05 06:01:29 volumio avahi-daemon[572]: New relevant interface wlan0.IPv4 for mDNS. Sep 05 06:01:29 volumio avahi-daemon[572]: Registering new address record for 192.168.2.6 on wlan0.IPv4. Sep 05 06:01:30 volumio sudo[10779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-05 06:00 Sep 05 06:01:30 volumio sudo[10779]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"