-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Mon 2025-06-16 05:08:43 CEST. -- Jun 16 05:07:00 voliera-volumio wpa_supplicant[1093]: wlan0: Associated with 08:40:f3:db:c2:91 Jun 16 05:07:00 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-CONNECTED - Connection to 08:40:f3:db:c2:91 completed [id=0 id_str=] Jun 16 05:07:00 voliera-volumio dhcpcd[576]: wlan0: carrier acquired Jun 16 05:07:00 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 16 05:07:00 voliera-volumio dhcpcd[576]: wlan0: IAID eb:90:74:d8 Jun 16 05:07:00 voliera-volumio dhcpcd[576]: wlan0: probing address 192.168.100.122/24 Jun 16 05:07:01 voliera-volumio dhcpcd[576]: wlan0: soliciting an IPv6 router Jun 16 05:07:01 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-DISCONNECTED bssid=08:40:f3:db:c2:91 reason=1 Jun 16 05:07:01 voliera-volumio dhcpcd[576]: wlan0: carrier lost Jun 16 05:07:01 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jun 16 05:07:01 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Jun 16 05:07:01 voliera-volumio volumio[1610]: info: Loading plugin "autostart"... Jun 16 05:07:02 voliera-volumio volumio[1610]: info: Applying required configuration parameters for plugin autostart Jun 16 05:07:02 voliera-volumio volumio[1610]: info: AutoStart - onVolumioStart - read config.json Jun 16 05:07:02 voliera-volumio volumio[1610]: info: Loading plugin "now_playing"... Jun 16 05:07:02 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jun 16 05:07:03 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jun 16 05:07:03 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jun 16 05:07:03 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jun 16 05:07:05 voliera-volumio volumio[1610]: info: Loading plugin "outputs"... Jun 16 05:07:05 voliera-volumio volumio[1610]: info: Loading plugin "albumart"... Jun 16 05:07:05 voliera-volumio volumio[1610]: info: Plugin example_plugin is not enabled Jun 16 05:07:05 voliera-volumio volumio[1610]: info: Loading plugin "inputs"... Jun 16 05:07:05 voliera-volumio volumio[1610]: info: Loading plugin "updater_comm"... Jun 16 05:07:05 voliera-volumio wpa_supplicant[1093]: wlan0: Trying to associate with SSID 'Internet' Jun 16 05:07:05 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Jun 16 05:07:06 voliera-volumio volumio[1610]: info: Plugin mpdemulation is not enabled Jun 16 05:07:06 voliera-volumio volumio[1610]: info: Loading plugin "rest_api"... Jun 16 05:07:06 voliera-volumio volumio[1610]: info: Loading plugin "websocket"... Jun 16 05:07:06 voliera-volumio volumio[1610]: info: Starting Socket.io Server version 2.3.0 Jun 16 05:07:06 voliera-volumio volumio[1610]: info: Loading plugin "minidlna"... Jun 16 05:07:06 voliera-volumio volumio[1610]: Forking 3 albumart workers Jun 16 05:07:06 voliera-volumio volumio[1610]: info: Applying required configuration parameters for plugin minidlna Jun 16 05:07:06 voliera-volumio volumio[1610]: info: Loading plugin "backup_restore"... Jun 16 05:07:07 voliera-volumio volumio[1610]: info: Applying required configuration parameters for plugin backup_restore Jun 16 05:07:07 voliera-volumio volumio[1610]: info: Loading plugin "Systeminfo"... Jun 16 05:07:08 voliera-volumio volumio[1610]: Starting albumart workers Jun 16 05:07:08 voliera-volumio volumio[1610]: Starting albumart workers Jun 16 05:07:08 voliera-volumio volumio[1610]: Starting albumart workers Jun 16 05:07:08 voliera-volumio volumio[1610]: info: Loading plugin "lastfm"... Jun 16 05:07:09 voliera-volumio volumio[1610]: info: Loading i18n strings for locale sk Jun 16 05:07:10 voliera-volumio volumio[1610]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jun 16 05:07:10 voliera-volumio volumio[1610]: Updating browse sources language Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:10 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jun 16 05:07:10 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jun 16 05:07:10 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::initPlayerControls Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 05:07:10 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jun 16 05:07:10 voliera-volumio volumio[1610]: Express server listening on port 3000 Jun 16 05:07:10 voliera-volumio volumio[1610]: [Metrics] WebUI: 26s 382.09ms Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreStateMachine::resetVolumioState Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreStateMachine::getcurrentVolume Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioRetrievevolume Jun 16 05:07:10 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:10 voliera-volumio volumio[1610]: info: Volumio Network Manager: Network status updated: 0 Jun 16 05:07:11 voliera-volumio sudo[1774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 05:07:11 voliera-volumio sudo[1776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 05:07:11 voliera-volumio sudo[1776]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:11 voliera-volumio sudo[1774]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:11 voliera-volumio sudo[1776]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:11 voliera-volumio sudo[1774]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:11 voliera-volumio volumio[1610]: Upnp client error: Error: This socket has been ended by the other party Jun 16 05:07:11 voliera-volumio volumio[1610]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Reloading queue from file Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Setting Device type: Raspberry PI Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreStateMachine::setRepeat null single undefined Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreStateMachine::pushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreStateMachine::setRandom true Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreStateMachine::pushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: VolumeController:: Volume=43 Mute =false Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreStateMachine::pushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreStateMachine::updateTrackBlock Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CorePlayQueue::getTrackBlock Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioRetrievevolume Jun 16 05:07:11 voliera-volumio sudo[1788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 16 05:07:11 voliera-volumio sudo[1788]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:11 voliera-volumio sudo[1788]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Upmpdcli Daemon Started Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Completed loading Core Plugins Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Preparing to generate the ALSA configuration file Jun 16 05:07:11 voliera-volumio volumio[1610]: info: VolumeController:: Volume=43 Mute =false Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreStateMachine::pushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Asound.conf file unchanged, so no further update is needed Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Output device has changed, restarting MPD Jun 16 05:07:11 voliera-volumio sudo[1793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 05:07:11 voliera-volumio sudo[1793]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:11 voliera-volumio volumio[1610]: info: Output device has changed, restarting Shairport Sync Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:11 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:11 voliera-volumio sudo[1793]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:12 voliera-volumio sudo[1796]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 05:07:12 voliera-volumio sudo[1796]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:12 voliera-volumio systemd[1]: Stopping Music Player Daemon... Jun 16 05:07:12 voliera-volumio volumio[1610]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 16 05:07:12 voliera-volumio volumio[1610]: info: ___________ START PLUGINS ___________ Jun 16 05:07:12 voliera-volumio volumio[1610]: info: ControllerMpd::onStart: Initializing MPD Jun 16 05:07:12 voliera-volumio volumio[1610]: info: Creating MPD Configuration file Jun 16 05:07:12 voliera-volumio systemd[1]: mpd.service: Succeeded. Jun 16 05:07:12 voliera-volumio systemd[1]: Stopped Music Player Daemon. Jun 16 05:07:12 voliera-volumio sudo[1803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 05:07:12 voliera-volumio sudo[1803]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:12 voliera-volumio systemd[1]: Starting Music Player Daemon... Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:12 voliera-volumio volumio[1610]: info: [1750043232204] CoreMusicLibrary::Adding element Mediálne servery Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:12 voliera-volumio sudo[1803]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:12 voliera-volumio sudo[1805]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 05:07:12 voliera-volumio sudo[1805]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:12 voliera-volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 16 05:07:12 voliera-volumio systemd[1]: mpd.service: Succeeded. Jun 16 05:07:12 voliera-volumio systemd[1]: Stopped Music Player Daemon. Jun 16 05:07:12 voliera-volumio systemd[1]: Starting Music Player Daemon... Jun 16 05:07:12 voliera-volumio volumio[1610]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:12 voliera-volumio volumio[1610]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:12 voliera-volumio volumio[1610]: info: [1750043232461] CoreMusicLibrary::Adding element Last_100 Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:12 voliera-volumio volumio[1610]: info: [1750043232468] CoreMusicLibrary::Adding element Webradio Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 05:07:12 voliera-volumio volumio[1610]: info: Initializing BBC Radios Jun 16 05:07:12 voliera-volumio volumio[1610]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:12 voliera-volumio sudo[1811]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 16 05:07:12 voliera-volumio sudo[1811]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:12 voliera-volumio sudo[1811]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:12 voliera-volumio volumio[1610]: info: Creating Spotify config file Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:12 voliera-volumio volumio[1610]: info: [1750043232862] CoreMusicLibrary::Adding element YouTube2 Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:12 voliera-volumio volumio[1610]: Cannot find translation for source YouTube2 Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:12 voliera-volumio volumio[1610]: info: [1750043232888] CoreMusicLibrary::Adding element YouTube Music Jun 16 05:07:12 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:12 voliera-volumio volumio[1610]: Cannot find translation for source YouTube2 Jun 16 05:07:12 voliera-volumio volumio[1610]: Cannot find translation for source YouTube Music Jun 16 05:07:12 voliera-volumio volumio[1610]: info: AutoStart - onStart Jun 16 05:07:12 voliera-volumio volumio[1610]: info: [now-playing] ConfigUpdater: config is up to date. Jun 16 05:07:12 voliera-volumio volumio[1610]: info: Loading i18n strings for locale sk Jun 16 05:07:12 voliera-volumio volumio[1610]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jun 16 05:07:13 voliera-volumio volumio[1610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [1750043233028] CoreMusicLibrary::Adding element LastFM Jun 16 05:07:13 voliera-volumio volumio[1610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:13 voliera-volumio volumio[1610]: Cannot find translation for source YouTube2 Jun 16 05:07:13 voliera-volumio volumio[1610]: Cannot find translation for source YouTube Music Jun 16 05:07:13 voliera-volumio volumio[1610]: Cannot find translation for source LastFM Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [LastFM] scrobbler initiated! Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [LastFM] extended logging: false Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [LastFM] try scrobble stream/radio plays: true Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [LastFM] Left init routine Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [LastFM] Socket already connected: true Jun 16 05:07:13 voliera-volumio volumio[1610]: info: Volumio Calling Home Jun 16 05:07:13 voliera-volumio wpa_supplicant[1093]: wlan0: Trying to associate with SSID 'Internet' Jun 16 05:07:13 voliera-volumio volumio-remote-updater[485]: [2025-06-16 05:07:13] [connect] Successful connection Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [now-playing] Fetching API key... Jun 16 05:07:13 voliera-volumio volumio[1610]: info: [now-playing] App is listening on port 4004. Jun 16 05:07:13 voliera-volumio volumio[1610]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jun 16 05:07:13 voliera-volumio volumio[1610]: Unhandled rejection Error: No sockets available, cannot start. Jun 16 05:07:13 voliera-volumio volumio[1610]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jun 16 05:07:13 voliera-volumio volumio[1610]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jun 16 05:07:13 voliera-volumio volumio[1610]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jun 16 05:07:13 voliera-volumio volumio[1610]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jun 16 05:07:13 voliera-volumio volumio[1610]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jun 16 05:07:13 voliera-volumio volumio[1610]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jun 16 05:07:13 voliera-volumio volumio[1610]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jun 16 05:07:13 voliera-volumio volumio[1610]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jun 16 05:07:13 voliera-volumio volumio[1610]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jun 16 05:07:13 voliera-volumio volumio[1610]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jun 16 05:07:13 voliera-volumio volumio[1610]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jun 16 05:07:13 voliera-volumio volumio[1610]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jun 16 05:07:13 voliera-volumio volumio[1610]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jun 16 05:07:13 voliera-volumio volumio[1610]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jun 16 05:07:13 voliera-volumio volumio[1610]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jun 16 05:07:13 voliera-volumio volumio[1610]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 16 05:07:13 voliera-volumio volumio[1610]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Jun 16 05:07:13 voliera-volumio volumio[1610]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 05:07:13 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Jun 16 05:07:13 voliera-volumio volumio[1610]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jun 16 05:07:13 voliera-volumio volumio[1610]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jun 16 05:07:13 voliera-volumio volumio[1610]: errno: -16, Jun 16 05:07:13 voliera-volumio volumio[1610]: code: 'EBUSY', Jun 16 05:07:13 voliera-volumio volumio[1610]: syscall: 'getaddrinfo', Jun 16 05:07:13 voliera-volumio volumio[1610]: hostname: 'ws.audioscrobbler.com' Jun 16 05:07:13 voliera-volumio volumio[1610]: } Jun 16 05:07:13 voliera-volumio volumio[1610]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 05:07:14 voliera-volumio sudo[1841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-16 05:06 Jun 16 05:07:14 voliera-volumio sudo[1841]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:15 voliera-volumio sudo[1841]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:15 voliera-volumio volumio-remote-updater[485]: [2025-06-16 05:07:15] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Jun 16 05:07:15 voliera-volumio volumio-remote-updater[485]: [2025-06-16 05:07:15] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Jun 16 05:07:15 voliera-volumio volumio-remote-updater[485]: [2025-06-16 05:07:15] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 16 05:07:15 voliera-volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jun 16 05:07:15 voliera-volumio sudo[1805]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:15 voliera-volumio sudo[1796]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:15 voliera-volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jun 16 05:07:15 voliera-volumio systemd[1]: Started dynamicswap service. Jun 16 05:07:15 voliera-volumio systemd[1]: dynamicswap.service: Succeeded. Jun 16 05:07:15 voliera-volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jun 16 05:07:15 voliera-volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Jun 16 05:07:15 voliera-volumio systemd[1]: Started dynamicswap service. Jun 16 05:07:15 voliera-volumio systemd[1]: Stopped Volumio Backend Module. Jun 16 05:07:15 voliera-volumio systemd[1]: Started Volumio Backend Module. Jun 16 05:07:15 voliera-volumio systemd[1]: dynamicswap.service: Succeeded. Jun 16 05:07:15 voliera-volumio mpd[1819]: Jun 16 05:07 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 16 05:07:15 voliera-volumio systemd[1]: Started Music Player Daemon. Jun 16 05:07:17 voliera-volumio nmbd[715]: [2025/06/16 05:07:17.605084, 0] ../source3/libsmb/nmblib.c:917(send_udp) Jun 16 05:07:17 voliera-volumio nmbd[715]: Packet send failed to 192.168.100.255(138) ERRNO=Network is unreachable Jun 16 05:07:17 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jun 16 05:07:17 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jun 16 05:07:17 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jun 16 05:07:17 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jun 16 05:07:19 voliera-volumio volumio[1855]: info: ------------------------------------------- Jun 16 05:07:19 voliera-volumio volumio[1855]: info: ----- Volumio3 ---- Jun 16 05:07:19 voliera-volumio volumio[1855]: info: ------------------------------------------- Jun 16 05:07:19 voliera-volumio volumio[1855]: info: ----- System startup ---- Jun 16 05:07:19 voliera-volumio volumio[1855]: info: ------------------------------------------- Jun 16 05:07:20 voliera-volumio wpa_supplicant[1093]: wlan0: Trying to associate with SSID 'Internet' Jun 16 05:07:21 voliera-volumio volumio[1855]: info: MYVOLUMIO Environment detected Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Plugin folders cleanup Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning into folder /volumio/app/plugins/ Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category audio_interface Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category miscellanea Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category music_service Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category plugins.json Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category system_controller Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category user_interface Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning into folder /data/plugins/ Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category music_service Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category system_controller Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Scanning category user_interface Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Plugin folders cleanup completed Jun 16 05:07:21 voliera-volumio volumio[1855]: info: ------------------------------------------- Jun 16 05:07:21 voliera-volumio volumio[1855]: info: ----- Core plugins startup ---- Jun 16 05:07:21 voliera-volumio volumio[1855]: info: ------------------------------------------- Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Loading plugins from folder /volumio/app/plugins/ Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Adding plugin upnp to MyMusic Plugins Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Loading plugins from folder /data/plugins/ Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Loading plugin "system"... Jun 16 05:07:21 voliera-volumio volumio[1855]: info: Loading plugin "appearance"... Jun 16 05:07:23 voliera-volumio volumio[1855]: info: Loading plugin "network"... Jun 16 05:07:23 voliera-volumio volumio[1855]: info: Refreshing Cached IP Addresses Jun 16 05:07:24 voliera-volumio sudo[1883]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 05:07:24 voliera-volumio sudo[1883]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:24 voliera-volumio sudo[1885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 05:07:24 voliera-volumio sudo[1885]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:24 voliera-volumio sudo[1885]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "services"... Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "alsa_controller"... Jun 16 05:07:24 voliera-volumio sudo[1883]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:24 voliera-volumio sudo[1896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 16 05:07:24 voliera-volumio sudo[1896]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:24 voliera-volumio sudo[1896]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:24 voliera-volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (67) Jun 16 05:07:24 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "wizard"... Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "networkfs"... Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Starting Udev Watcher for removable devices Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Ignoring mount for partition: boot Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Ignoring mount for partition: volumio Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Ignoring mount for partition: volumio_data Jun 16 05:07:24 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "volumio_command_line_client"... Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "upnp"... Jun 16 05:07:24 voliera-volumio volumio[1855]: info: [1750043244472] Starting Upmpd Daemon Jun 16 05:07:24 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "my_music"... Jun 16 05:07:24 voliera-volumio volumio[1855]: info: Loading plugin "mpd"... Jun 16 05:07:25 voliera-volumio volumio[1855]: info: Loading plugin "upnp_browser"... Jun 16 05:07:25 voliera-volumio volumio-remote-updater[485]: [2025-06-16 05:07:25] [connect] Successful connection Jun 16 05:07:25 voliera-volumio volumio[1855]: info: Loading plugin "alarm-clock"... Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Loading plugin "airplay_emulation"... Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Starting Shairport Sync Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Loading plugin "last_100"... Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Loading plugin "webradio"... Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Loading plugin "i2s_dacs"... Jun 16 05:07:26 voliera-volumio volumio[1855]: info: I2S DAC not set, start Auto-detection Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Loading plugin "volumiodiscovery"... Jun 16 05:07:26 voliera-volumio volumio[1855]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 16 05:07:26 voliera-volumio volumio[1855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 05:07:26 voliera-volumio volumio[1855]: *** WARNING *** For more information see Jun 16 05:07:26 voliera-volumio volumio[1855]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 16 05:07:26 voliera-volumio node[1855]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 16 05:07:26 voliera-volumio volumio[1855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 05:07:26 voliera-volumio volumio[1855]: *** WARNING *** For more information see Jun 16 05:07:26 voliera-volumio node[1855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 05:07:26 voliera-volumio node[1855]: *** WARNING *** For more information see Jun 16 05:07:26 voliera-volumio node[1855]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 16 05:07:26 voliera-volumio node[1855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 16 05:07:26 voliera-volumio node[1855]: *** WARNING *** For more information see Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Discovery: Started advertising with name: voliera-volumio Jun 16 05:07:26 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 05:07:26 voliera-volumio volumio[1855]: info: Loading plugin "spop"... Jun 16 05:07:26 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=08:40:f3:db:c2:a1 status_code=16 Jun 16 05:07:28 voliera-volumio volumio[1855]: info: Loading plugin "youtube2"... Jun 16 05:07:30 voliera-volumio volumio[1855]: info: Loading plugin "ytmusic"... Jun 16 05:07:32 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jun 16 05:07:32 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jun 16 05:07:32 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jun 16 05:07:32 voliera-volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jun 16 05:07:33 voliera-volumio volumio[1855]: info: Loading plugin "autostart"... Jun 16 05:07:33 voliera-volumio volumio[1855]: info: Applying required configuration parameters for plugin autostart Jun 16 05:07:33 voliera-volumio volumio[1855]: info: AutoStart - onVolumioStart - read config.json Jun 16 05:07:33 voliera-volumio volumio[1855]: info: Loading plugin "now_playing"... Jun 16 05:07:34 voliera-volumio wpa_supplicant[1093]: wlan0: Trying to associate with SSID 'Internet' Jun 16 05:07:35 voliera-volumio wpa_supplicant[1093]: wlan0: Associated with 08:40:f3:db:c2:94 Jun 16 05:07:35 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-CONNECTED - Connection to 08:40:f3:db:c2:94 completed [id=0 id_str=] Jun 16 05:07:35 voliera-volumio dhcpcd[576]: wlan0: carrier acquired Jun 16 05:07:35 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 16 05:07:35 voliera-volumio wpa_supplicant[1093]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Jun 16 05:07:35 voliera-volumio dhcpcd[576]: wlan0: IAID eb:90:74:d8 Jun 16 05:07:35 voliera-volumio dhcpcd[576]: wlan0: probing address 192.168.100.122/24 Jun 16 05:07:35 voliera-volumio dhcpcd[576]: wlan0: soliciting an IPv6 router Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Loading plugin "outputs"... Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Loading plugin "albumart"... Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Plugin example_plugin is not enabled Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Loading plugin "inputs"... Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Loading plugin "updater_comm"... Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Plugin mpdemulation is not enabled Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Loading plugin "rest_api"... Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Loading plugin "websocket"... Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Starting Socket.io Server version 2.3.0 Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Loading plugin "minidlna"... Jun 16 05:07:36 voliera-volumio volumio[1855]: info: Applying required configuration parameters for plugin minidlna Jun 16 05:07:37 voliera-volumio volumio[1855]: Forking 3 albumart workers Jun 16 05:07:37 voliera-volumio volumio[1855]: info: Loading plugin "backup_restore"... Jun 16 05:07:37 voliera-volumio volumio[1855]: info: Applying required configuration parameters for plugin backup_restore Jun 16 05:07:37 voliera-volumio volumio[1855]: info: Loading plugin "Systeminfo"... Jun 16 05:07:38 voliera-volumio volumio[1855]: info: Loading plugin "lastfm"... Jun 16 05:07:38 voliera-volumio volumio[1855]: Starting albumart workers Jun 16 05:07:38 voliera-volumio volumio[1855]: Starting albumart workers Jun 16 05:07:38 voliera-volumio volumio[1855]: Starting albumart workers Jun 16 05:07:39 voliera-volumio volumio[1855]: info: Loading i18n strings for locale sk Jun 16 05:07:39 voliera-volumio volumio[1855]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jun 16 05:07:39 voliera-volumio volumio[1855]: Updating browse sources language Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::initPlayerControls Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 05:07:39 voliera-volumio volumio[1855]: Express server listening on port 3000 Jun 16 05:07:39 voliera-volumio volumio[1855]: [Metrics] WebUI: 21s 264.34ms Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreStateMachine::resetVolumioState Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreStateMachine::getcurrentVolume Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioRetrievevolume Jun 16 05:07:39 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:40 voliera-volumio sudo[2043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 05:07:40 voliera-volumio sudo[2043]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:40 voliera-volumio sudo[2049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 05:07:40 voliera-volumio sudo[2049]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:40 voliera-volumio sudo[2049]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:40 voliera-volumio sudo[2043]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:40 voliera-volumio volumio[1855]: info: Volumio Network Manager: Network status updated: 0 Jun 16 05:07:40 voliera-volumio volumio-remote-updater[485]: [2025-06-16 05:07:40] [connect] Successful connection Jun 16 05:07:40 voliera-volumio volumio[1855]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jun 16 05:07:40 voliera-volumio volumio[1855]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Jun 16 05:07:40 voliera-volumio volumio[1855]: info: Cannot use regular scanning, forcing with ap-force Jun 16 05:07:40 voliera-volumio sudo[2076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jun 16 05:07:40 voliera-volumio sudo[2076]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:40 voliera-volumio dhcpcd[576]: wlan0: using static address 192.168.100.122/24 Jun 16 05:07:40 voliera-volumio avahi-daemon[478]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.122. Jun 16 05:07:40 voliera-volumio avahi-daemon[478]: New relevant interface wlan0.IPv4 for mDNS. Jun 16 05:07:40 voliera-volumio dhcpcd[576]: wlan0: adding route to 192.168.100.0/24 Jun 16 05:07:40 voliera-volumio avahi-daemon[478]: Registering new address record for 192.168.100.122 on wlan0.IPv4. Jun 16 05:07:40 voliera-volumio dhcpcd[576]: wlan0: adding default route via 192.168.100.252 Jun 16 05:07:42 voliera-volumio ntpd[722]: Listen normally on 4 wlan0 192.168.100.122:123 Jun 16 05:07:42 voliera-volumio ntpd[722]: new interface(s) found: waking up resolver Jun 16 05:07:44 voliera-volumio sudo[2076]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:44 voliera-volumio volumio[1855]: info: Volumio Network Manager: Network status updated: 2 Jun 16 05:07:44 voliera-volumio volumio[1855]: info: VolumeController:: Volume=43 Mute =false Jun 16 05:07:44 voliera-volumio volumio[1855]: info: CoreStateMachine::pushState Jun 16 05:07:44 voliera-volumio volumio[1855]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:44 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 05:07:44 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:44 voliera-volumio volumio[1855]: info: CoreStateMachine::updateTrackBlock Jun 16 05:07:44 voliera-volumio volumio[1855]: info: CorePlayQueue::getTrackBlock Jun 16 05:07:44 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioRetrievevolume Jun 16 05:07:44 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 16 05:07:44 voliera-volumio volumio-remote-updater[485]: [2025-06-16 05:07:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1750043260 101 Jun 16 05:07:44 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 2 Jun 16 05:07:44 voliera-volumio volumio[1855]: info: Reloading queue from file Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreStateMachine::setRepeat null single undefined Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreStateMachine::pushState Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreStateMachine::setRandom true Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreStateMachine::pushState Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Setting Device type: Raspberry PI Jun 16 05:07:45 voliera-volumio volumio[1855]: info: VolumeController:: Volume=43 Mute =false Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreStateMachine::pushState Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CorePlayQueue::getTrack 0 Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioPushState Jun 16 05:07:45 voliera-volumio sudo[2123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 16 05:07:45 voliera-volumio sudo[2123]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:45 voliera-volumio sudo[2123]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Upmpdcli Daemon Started Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Completed loading Core Plugins Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Preparing to generate the ALSA configuration file Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Asound.conf file unchanged, so no further update is needed Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Output device has changed, restarting MPD Jun 16 05:07:45 voliera-volumio sudo[2126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 05:07:45 voliera-volumio sudo[2126]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Output device has changed, restarting Shairport Sync Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:45 voliera-volumio sudo[2126]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:45 voliera-volumio sudo[2128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 05:07:45 voliera-volumio sudo[2128]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:45 voliera-volumio systemd[1]: Stopping Music Player Daemon... Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 16 05:07:45 voliera-volumio volumio[1855]: info: ___________ START PLUGINS ___________ Jun 16 05:07:45 voliera-volumio systemd[1]: mpd.service: Succeeded. Jun 16 05:07:45 voliera-volumio systemd[1]: Stopped Music Player Daemon. Jun 16 05:07:45 voliera-volumio volumio[1855]: info: ControllerMpd::onStart: Initializing MPD Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Creating MPD Configuration file Jun 16 05:07:45 voliera-volumio systemd[1]: Starting Music Player Daemon... Jun 16 05:07:45 voliera-volumio sudo[2136]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 05:07:45 voliera-volumio sudo[2136]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:45 voliera-volumio volumio[1855]: info: [1750043265721] CoreMusicLibrary::Adding element Mediálne servery Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:45 voliera-volumio sudo[2136]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:45 voliera-volumio sudo[2138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 05:07:45 voliera-volumio sudo[2138]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:45 voliera-volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 16 05:07:45 voliera-volumio systemd[1]: mpd.service: Succeeded. Jun 16 05:07:45 voliera-volumio systemd[1]: Stopped Music Player Daemon. Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:45 voliera-volumio systemd[1]: Starting Music Player Daemon... Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:45 voliera-volumio volumio[1855]: info: [1750043265973] CoreMusicLibrary::Adding element Last_100 Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:45 voliera-volumio volumio[1855]: info: [1750043265980] CoreMusicLibrary::Adding element Webradio Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:45 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 05:07:45 voliera-volumio volumio[1855]: info: Initializing BBC Radios Jun 16 05:07:46 voliera-volumio volumio[1855]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:46 voliera-volumio sudo[2144]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 16 05:07:46 voliera-volumio sudo[2144]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:46 voliera-volumio sudo[2144]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:46 voliera-volumio volumio[1855]: info: Creating Spotify config file Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [1750043266335] CoreMusicLibrary::Adding element YouTube2 Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:46 voliera-volumio volumio[1855]: Cannot find translation for source YouTube2 Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [1750043266350] CoreMusicLibrary::Adding element YouTube Music Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:46 voliera-volumio volumio[1855]: Cannot find translation for source YouTube2 Jun 16 05:07:46 voliera-volumio volumio[1855]: Cannot find translation for source YouTube Music Jun 16 05:07:46 voliera-volumio volumio[1855]: info: AutoStart - onStart Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [now-playing] ConfigUpdater: config is up to date. Jun 16 05:07:46 voliera-volumio volumio[1855]: info: Loading i18n strings for locale sk Jun 16 05:07:46 voliera-volumio volumio[1855]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [1750043266494] CoreMusicLibrary::Adding element LastFM Jun 16 05:07:46 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 05:07:46 voliera-volumio volumio[1855]: Cannot find translation for source YouTube2 Jun 16 05:07:46 voliera-volumio volumio[1855]: Cannot find translation for source YouTube Music Jun 16 05:07:46 voliera-volumio volumio[1855]: Cannot find translation for source LastFM Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [LastFM] scrobbler initiated! Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [LastFM] extended logging: false Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [LastFM] try scrobble stream/radio plays: true Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [LastFM] Left init routine Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [LastFM] Socket already connected: true Jun 16 05:07:46 voliera-volumio volumio[1855]: info: Volumio Calling Home Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [now-playing] Fetching API key... Jun 16 05:07:46 voliera-volumio volumio[1855]: info: [now-playing] App is listening on port 4004. Jun 16 05:07:46 voliera-volumio volumio[1855]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jun 16 05:07:46 voliera-volumio volumio[1855]: info: MPD Permissions set Jun 16 05:07:46 voliera-volumio volumio[1855]: info: MPD Permissions set Jun 16 05:07:46 voliera-volumio volumio[1855]: info: Spotify config file written Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio sudo[2166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 16 05:07:47 voliera-volumio sudo[2166]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:07:47 voliera-volumio volumio[1855]: info: minidlna: Found miniDLNA version 1.2.1 Jun 16 05:07:47 voliera-volumio volumio[1855]: info: minidlna: Starting minidlna.service Jun 16 05:07:47 voliera-volumio sudo[2178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Jun 16 05:07:47 voliera-volumio sudo[2178]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:47 voliera-volumio systemd[1]: Started go-librespot Daemon. Jun 16 05:07:47 voliera-volumio volumio[1855]: info: Starting Shairport Sync Jun 16 05:07:47 voliera-volumio go-librespot[2177]: Librespot-go daemon starting... Jun 16 05:07:47 voliera-volumio sudo[2166]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:47 voliera-volumio volumio[1855]: info: Starting Shairport Sync Jun 16 05:07:47 voliera-volumio volumio[1855]: info: Starting Shairport Sync Jun 16 05:07:47 voliera-volumio systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. Jun 16 05:07:47 voliera-volumio sudo[2178]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:47 voliera-volumio sudo[2184]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 16 05:07:47 voliera-volumio sudo[2187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 16 05:07:47 voliera-volumio sudo[2187]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:47 voliera-volumio sudo[2184]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:47 voliera-volumio sudo[2182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 16 05:07:47 voliera-volumio volumio[1855]: info: minidlna: systemctl start minidlna.service succeeded. Jun 16 05:07:47 voliera-volumio sudo[2182]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 05:07:47 voliera-volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 16 05:07:47 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to 192.168.100.122:3000 from 192.168.100.121 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 16 05:07:48 voliera-volumio systemd[1]: shairport-sync.service: Succeeded. Jun 16 05:07:48 voliera-volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 16 05:07:48 voliera-volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 16 05:07:48 voliera-volumio sudo[2184]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:48 voliera-volumio volumio[1855]: info: Shairport-Sync Started Jun 16 05:07:48 voliera-volumio sudo[2187]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:48 voliera-volumio sudo[2182]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:48 voliera-volumio volumio[1855]: Error adding Membership: Error: addMembership EINVAL Jun 16 05:07:48 voliera-volumio volumio[1855]: info: Shairport-Sync Started Jun 16 05:07:48 voliera-volumio volumio[1855]: info: Shairport-Sync Started Jun 16 05:07:49 voliera-volumio mpd[2159]: Jun 16 05:07 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 16 05:07:49 voliera-volumio systemd[1]: Started Music Player Daemon. Jun 16 05:07:49 voliera-volumio sudo[2128]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:49 voliera-volumio sudo[2138]: pam_unix(sudo:session): session closed for user root Jun 16 05:07:49 voliera-volumio go-librespot[2177]: time="2025-06-16T05:07:49+02:00" level=info msg="generated new device id: 3061c97c2b926b2fc853f66707b0aa7d683dd55c" Jun 16 05:07:49 voliera-volumio go-librespot[2177]: time="2025-06-16T05:07:49+02:00" level=debug msg="stored credentials found for 31ykrfcoejvq3eri6uosxaghgvou" Jun 16 05:07:49 voliera-volumio volumio[1855]: info: Completed starting Core Plugins Jun 16 05:07:49 voliera-volumio volumio[1855]: info: ------------------------------------------- Jun 16 05:07:49 voliera-volumio volumio[1855]: info: ----- MyVolumio plugins startup ---- Jun 16 05:07:49 voliera-volumio volumio[1855]: info: ------------------------------------------- Jun 16 05:07:49 voliera-volumio volumio[1855]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 16 05:07:49 voliera-volumio volumio[1855]: error: MPD error: The expression evaluated to a falsy value: Jun 16 05:07:49 voliera-volumio volumio[1855]: assert.ok(self.idling) Jun 16 05:07:49 voliera-volumio volumio[1855]: error: The expression evaluated to a falsy value: Jun 16 05:07:49 voliera-volumio volumio[1855]: assert.ok(self.idling) Jun 16 05:07:49 voliera-volumio volumio[1855]: error: updateQueue error: null Jun 16 05:07:49 voliera-volumio volumio[1855]: info: MPD running with PID2159 Jun 16 05:07:49 voliera-volumio volumio[1855]: ,establishing connection Jun 16 05:07:49 voliera-volumio volumio[1855]: error: updateQueue error: null Jun 16 05:07:50 voliera-volumio volumio[1855]: info: go-librespot daemon successfully initialized Jun 16 05:07:53 voliera-volumio volumio[1855]: info: Initializing connection to go-librespot Websocket Jun 16 05:07:54 voliera-volumio volumio[1855]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 16 05:08:04 voliera-volumio ntpd[722]: Soliciting pool server 185.242.56.3 Jun 16 05:08:06 voliera-volumio volumio[1855]: info: AutoStart - Plugin is starting Jun 16 05:08:06 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioGetQueue Jun 16 05:08:06 voliera-volumio volumio[1855]: info: CoreStateMachine::getQueue Jun 16 05:08:06 voliera-volumio volumio[1855]: info: CorePlayQueue::getQueue Jun 16 05:08:09 voliera-volumio volumio[1855]: error: MyVolumio Plugin failed to start in a timely fashion Jun 16 05:08:09 voliera-volumio volumio[1855]: [Metrics] CommandRouter: 49s 900.00ms Jun 16 05:08:09 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumiosetStartupVolume Jun 16 05:08:09 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 05:08:09 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:08:09 voliera-volumio volumio[1855]: info: CoreCommandRouter::Close All Modals sent Jun 16 05:08:09 voliera-volumio volumio[1855]: info: CoreCommandRouter::Close All Modals sent Jun 16 05:08:10 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 16 05:08:10 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 16 05:08:10 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 16 05:08:10 voliera-volumio volumio[1855]: info: Version has changed, forcing UI Reload Jun 16 05:08:10 voliera-volumio volumio[1855]: info: CoreCommandRouter::Reload Ui Jun 16 05:08:14 voliera-volumio volumio[1855]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Jun 16 05:08:16 voliera-volumio volumio[1855]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jun 16 05:08:16 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:08:16 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 05:08:16 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 05:08:16 voliera-volumio volumio[1855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 16 05:08:16 voliera-volumio volumio[1855]: info: BOOT COMPLETED Jun 16 05:08:17 voliera-volumio go-librespot[2177]: time="2025-06-16T05:08:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 16 05:08:17 voliera-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 16 05:08:17 voliera-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 16 05:08:20 voliera-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 16 05:08:20 voliera-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jun 16 05:08:20 voliera-volumio systemd[1]: Stopped go-librespot Daemon. Jun 16 05:08:20 voliera-volumio systemd[1]: Started go-librespot Daemon. Jun 16 05:08:20 voliera-volumio go-librespot[2261]: Librespot-go daemon starting... Jun 16 05:08:20 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:20+02:00" level=info msg="generated new device id: 41ad04dbe177c22af06286b2cd1f326bbef4a57a" Jun 16 05:08:20 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:20+02:00" level=debug msg="stored credentials found for 31ykrfcoejvq3eri6uosxaghgvou" Jun 16 05:08:24 voliera-volumio volumio[1855]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.816&uuid=830d1d94af7379998e2db9d226ca7b15" http://updates.volumio.org/downloader-v1/track-device Jun 16 05:08:24 voliera-volumio volumio[1855]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 16 05:08:24 voliera-volumio volumio[1855]: Dload Upload Total Spent Left Speed Jun 16 05:08:24 voliera-volumio volumio[1855]: [2.2K blob data] Jun 16 05:08:24 voliera-volumio volumio[1855]: retrying in 5 seconds, trial 0 Jun 16 05:08:24 voliera-volumio volumio[1855]: info: Volumio Calling Home Jun 16 05:08:32 voliera-volumio ntpd[722]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 16 05:08:40 voliera-volumio ntpd[722]: Soliciting pool server 212.55.254.189 Jun 16 05:08:40 voliera-volumio ntpd[722]: Soliciting pool server 213.81.129.99 Jun 16 05:08:40 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:40+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 16 05:08:40 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:40+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 16 05:08:40 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:40+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 16 05:08:40 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:40+02:00" level=debug msg="zeroconf server listening on port 36769" Jun 16 05:08:41 voliera-volumio ntpd[722]: Soliciting pool server 185.242.56.5 Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: adding 725fe54a-fd77-4c41-9b58-cc26417a8347 Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: Found device voliera-volumio Jun 16 05:08:41 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioGetState Jun 16 05:08:41 voliera-volumio volumio[1855]: info: CorePlayQueue::getTrack 0 Jun 16 05:08:41 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 16 05:08:41 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:41+02:00" level=debug msg="obtained new client token: AAADaOlJqi6A5RHAhkj33dW/hFW8X2XsWJnYxUxWjsFSrpzjwZz8EJI5VRuL7Z1q4XZTwgNZ5CRNH8WYjCR1QcgmE/ms89G+KAx4vPFTNFWTcXeHA5Vu4aIOLXAbSHUYsSYGBJk7icnB1Lq2qbFBPO3UaFnnug7bq8sDURSTaL/Ewiq9pTrIee1yuLQWU2k8H0QHMDrYiJrcRswmpAcdQrq4m6EFmpS+ij3ksZVs4I7pRepAPbGn1wcGQFs=" Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: adding fd6d849b-1bfb-449f-a5a6-d7a016a7445c Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: Found device altanok-volumio Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: Connecting to remote: 192.168.100.121 Jun 16 05:08:41 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 16 05:08:41 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:41+02:00" level=debug msg="completed keyexchange" Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: adding c72f228d-a1b0-405d-aa53-37736fea7251 Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: Found device obyvacka-volumio Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: Connecting to remote: 192.168.100.120 Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Discovery: Connected to remote: 192.168.100.121 Jun 16 05:08:41 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:41+02:00" level=debug msg="new websocket client" Jun 16 05:08:41 voliera-volumio volumio[1855]: info: Connection to go-librespot Websocket established Jun 16 05:08:41 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jun 16 05:08:41 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 16 05:08:41 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 16 05:08:41 voliera-volumio volumio[1855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 16 05:08:42 voliera-volumio volumio[1855]: info: CoreCommandRouter::volumioGetState Jun 16 05:08:42 voliera-volumio volumio[1855]: info: CorePlayQueue::getTrack 0 Jun 16 05:08:42 voliera-volumio ntpd[722]: Soliciting pool server 84.245.104.80 Jun 16 05:08:42 voliera-volumio volumio[1855]: (node:1855) UnhandledPromiseRejectionWarning: Error: Could not obtain API key Jun 16 05:08:42 voliera-volumio volumio[1855]: at doGet (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:124:19) Jun 16 05:08:42 voliera-volumio volumio[1855]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Jun 16 05:08:42 voliera-volumio volumio[1855]: (Use `node --trace-warnings ...` to show where the warning was created) Jun 16 05:08:42 voliera-volumio volumio[1855]: (node:1855) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3) Jun 16 05:08:42 voliera-volumio volumio[1855]: (node:1855) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="completed challenge" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="authenticated as 31ykrfcoejvq3eri6uosxaghgvou" Jun 16 05:08:42 voliera-volumio volumio[1855]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="authenticated as 31ykrfcoejvq3eri6uosxaghgvou" Jun 16 05:08:42 voliera-volumio volumio[1855]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Jun 16 05:08:42 voliera-volumio volumio[1855]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jun 16 05:08:42 voliera-volumio volumio[1855]: errno: -3007, Jun 16 05:08:42 voliera-volumio volumio[1855]: code: 'ENOTFOUND', Jun 16 05:08:42 voliera-volumio volumio[1855]: syscall: 'getaddrinfo', Jun 16 05:08:42 voliera-volumio volumio[1855]: hostname: 'ws.audioscrobbler.com' Jun 16 05:08:42 voliera-volumio volumio[1855]: } Jun 16 05:08:42 voliera-volumio volumio[1855]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="dealer connection opened" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="initializing zeroconf session, username: 31ykrfcoejvq3eri6uosxaghgvou" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="autoplay enabled: false" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="received connection id: N2YxZTljYWMtODlkZi00ZmU5LTgwYzItMmY4MzBhYjYwZDNiK2RlYWxlcit0Y3A6Ly8wYWNhNDFlOS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArOEQ3QTdENjczODhBNEI3RkZDNkY5NzJBRTE5Rjc5ODVDOTI5RTE5QTYxQjE4NDA3N0NEM0E3M0NCMTMzMjA0MA==" Jun 16 05:08:42 voliera-volumio go-librespot[2261]: time="2025-06-16T05:08:42+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 16 05:08:43 voliera-volumio ntpd[722]: Soliciting pool server 2001:470:6f:483::1 Jun 16 05:08:43 voliera-volumio sudo[2394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-16 05:07 Jun 16 05:08:43 voliera-volumio sudo[2394]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"