-- Logs begin at Thu 2025-05-22 18:20:51 CEST, end at Thu 2025-05-22 18:22:19 CEST. -- May 22 18:21:00 volumio volumio[876]: info: ------------------------------------------- May 22 18:21:00 volumio volumio[876]: info: ----- Volumio3 ---- May 22 18:21:00 volumio volumio[876]: info: ------------------------------------------- May 22 18:21:00 volumio volumio[876]: info: ----- System startup ---- May 22 18:21:00 volumio volumio[876]: info: ------------------------------------------- May 22 18:21:01 volumio volumio[876]: info: MYVOLUMIO Environment detected May 22 18:21:01 volumio volumio[876]: info: Plugin folders cleanup May 22 18:21:01 volumio volumio[876]: info: Scanning into folder /volumio/app/plugins/ May 22 18:21:01 volumio volumio[876]: info: Scanning category audio_interface May 22 18:21:01 volumio volumio[876]: info: Scanning category miscellanea May 22 18:21:01 volumio volumio[876]: info: Scanning category music_service May 22 18:21:01 volumio volumio[876]: info: Scanning category plugins.json May 22 18:21:01 volumio volumio[876]: info: Scanning category system_controller May 22 18:21:01 volumio volumio[876]: info: Scanning category user_interface May 22 18:21:01 volumio volumio[876]: info: Scanning into folder /data/plugins/ May 22 18:21:01 volumio volumio[876]: info: Scanning category music_service May 22 18:21:01 volumio volumio[876]: info: Scanning category system_hardware May 22 18:21:01 volumio volumio[876]: info: Plugin folders cleanup completed May 22 18:21:01 volumio volumio[876]: info: ------------------------------------------- May 22 18:21:01 volumio volumio[876]: info: ----- Core plugins startup ---- May 22 18:21:01 volumio volumio[876]: info: ------------------------------------------- May 22 18:21:01 volumio volumio[876]: info: Loading plugins from folder /volumio/app/plugins/ May 22 18:21:01 volumio volumio[876]: info: Adding plugin upnp to MyMusic Plugins May 22 18:21:01 volumio volumio[876]: info: Adding plugin airplay_emulation to MyMusic Plugins May 22 18:21:01 volumio volumio[876]: info: Adding plugin upnp_browser to MyMusic Plugins May 22 18:21:01 volumio volumio[876]: info: Loading plugins from folder /data/plugins/ May 22 18:21:01 volumio volumio[876]: info: Loading plugin "system"... May 22 18:21:01 volumio volumio[876]: info: Loading plugin "appearance"... May 22 18:21:02 volumio volumio[876]: info: Loading plugin "network"... May 22 18:21:02 volumio volumio[876]: info: Refreshing Cached IP Addresses May 22 18:21:02 volumio volumio[876]: info: Loading plugin "services"... May 22 18:21:02 volumio sudo[1123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 18:21:02 volumio sudo[1125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 18:21:02 volumio sudo[1123]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:02 volumio sudo[1125]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:02 volumio volumio[876]: info: Loading plugin "alsa_controller"... May 22 18:21:02 volumio sudo[1134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 22 18:21:02 volumio sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:02 volumio sudo[1123]: pam_unix(sudo:session): session closed for user root May 22 18:21:02 volumio sudo[1125]: pam_unix(sudo:session): session closed for user root May 22 18:21:02 volumio sudo[1134]: pam_unix(sudo:session): session closed for user root May 22 18:21:03 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 18:21:03 volumio volumio[876]: info: Loading plugin "wizard"... May 22 18:21:03 volumio volumio[876]: info: Loading plugin "networkfs"... May 22 18:21:03 volumio volumio[876]: info: Starting Udev Watcher for removable devices May 22 18:21:03 volumio volumio[876]: info: Mounting Device EFI May 22 18:21:03 volumio sudo[1159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb1 /mnt/USB/EFI -o noatime,dmask=0000,fmask=0000,iocharset=utf8 May 22 18:21:03 volumio sudo[1159]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:03 volumio kernel: FAT-fs (sdb1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! May 22 18:21:03 volumio kernel: FAT-fs (sdb1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. May 22 18:21:03 volumio sudo[1159]: pam_unix(sudo:session): session closed for user root May 22 18:21:03 volumio volumio[876]: info: Mounting Device PenDrive May 22 18:21:03 volumio sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb2 /mnt/USB/PenDrive -o noatime May 22 18:21:03 volumio sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:03 volumio sudo[1165]: pam_unix(sudo:session): session closed for user root May 22 18:21:03 volumio volumio[876]: info: Ignoring mount for partition: boot May 22 18:21:03 volumio volumio[876]: info: Ignoring mount for partition: volumio May 22 18:21:03 volumio volumio[876]: info: Ignoring mount for partition: volumio_data May 22 18:21:03 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 22 18:21:03 volumio volumio[876]: info: Loading plugin "volumio_command_line_client"... May 22 18:21:03 volumio volumio[876]: info: Loading plugin "upnp"... May 22 18:21:03 volumio volumio[876]: info: [1747930863440] Starting Upmpd Daemon May 22 18:21:03 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 22 18:21:03 volumio volumio[876]: info: Loading plugin "my_music"... May 22 18:21:03 volumio volumio[876]: info: Loading plugin "mpd"... May 22 18:21:03 volumio dhcpcd[763]: eth0: probing for an IPv4LL address May 22 18:21:03 volumio dhcpcd[763]: eth0: DHCP lease expired May 22 18:21:03 volumio dhcpcd[763]: eth0: soliciting a DHCP lease May 22 18:21:03 volumio volumio[876]: info: Loading plugin "upnp_browser"... May 22 18:21:03 volumio dbus-daemon[671]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.6' (uid=0 pid=1096 comm="/usr/lib/chromium/chromium --show-component-extens") May 22 18:21:03 volumio systemd[1]: Starting Bluetooth service... May 22 18:21:04 volumio kernel: cryptd: max_cpu_qlen set to 1000 May 22 18:21:04 volumio kernel: Bluetooth: Core ver 2.22 May 22 18:21:04 volumio kernel: NET: Registered PF_BLUETOOTH protocol family May 22 18:21:04 volumio kernel: Bluetooth: HCI device and connection manager initialized May 22 18:21:04 volumio kernel: Bluetooth: HCI socket layer initialized May 22 18:21:04 volumio kernel: Bluetooth: L2CAP socket layer initialized May 22 18:21:04 volumio kernel: Bluetooth: SCO socket layer initialized May 22 18:21:04 volumio bluetoothd[1189]: Bluetooth daemon 5.50 May 22 18:21:04 volumio sh[607]: eth0: probing for an IPv4LL address May 22 18:21:04 volumio dhcpcd[654]: eth0: probing for an IPv4LL address May 22 18:21:04 volumio bluetoothd[1189]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf May 22 18:21:04 volumio dbus-daemon[671]: [system] Successfully activated service 'org.bluez' May 22 18:21:04 volumio systemd[1]: Started Bluetooth service. May 22 18:21:04 volumio sh[607]: eth0: DHCP lease expired May 22 18:21:04 volumio dhcpcd[654]: eth0: DHCP lease expired May 22 18:21:04 volumio bluetoothd[1189]: Starting SDP server May 22 18:21:04 volumio bluetoothd[1189]: Excluding (cli) sap May 22 18:21:04 volumio sh[607]: eth0: soliciting a DHCP lease May 22 18:21:04 volumio dhcpcd[654]: eth0: soliciting a DHCP lease May 22 18:21:04 volumio bluetoothd[1189]: Bluetooth management interface 1.22 initialized May 22 18:21:04 volumio dbus-daemon[671]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.7' (uid=0 pid=1189 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") May 22 18:21:04 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 May 22 18:21:04 volumio kernel: Bluetooth: BNEP filters: protocol multicast May 22 18:21:04 volumio kernel: Bluetooth: BNEP socket layer initialized May 22 18:21:04 volumio systemd[1]: Starting Hostname Service... May 22 18:21:04 volumio volumio[876]: info: Loading plugin "alarm-clock"... May 22 18:21:04 volumio volumio-time-update[658]: volumio-time-update-util: Fetching time from Volumio... May 22 18:21:04 volumio volumio-time-update[658]: volumio-time-update-util: Date not found in response May 22 18:21:04 volumio volumio-time-update[658]: volumio-time-update-util: Retrying in 5 seconds... May 22 18:21:04 volumio dbus-daemon[671]: [system] Successfully activated service 'org.freedesktop.hostname1' May 22 18:21:04 volumio systemd[1]: Started Hostname Service. May 22 18:21:04 volumio volumio[876]: info: Loading plugin "airplay_emulation"... May 22 18:21:05 volumio volumio[876]: info: Starting Shairport Sync May 22 18:21:05 volumio volumio[876]: info: Loading plugin "last_100"... May 22 18:21:05 volumio volumio[876]: info: Loading plugin "webradio"... May 22 18:21:05 volumio volumio[876]: info: Loading plugin "i2s_dacs"... May 22 18:21:05 volumio volumio[876]: info: I2S DAC not set, start Auto-detection May 22 18:21:05 volumio volumio[876]: info: Loading plugin "volumiodiscovery"... May 22 18:21:05 volumio volumio[876]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 22 18:21:05 volumio node[876]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 22 18:21:05 volumio volumio[876]: *** WARNING *** Please fix your application to use the native API of Avahi! May 22 18:21:05 volumio node[876]: *** WARNING *** Please fix your application to use the native API of Avahi! May 22 18:21:05 volumio volumio[876]: *** WARNING *** For more information see May 22 18:21:05 volumio node[876]: *** WARNING *** For more information see May 22 18:21:05 volumio volumio[876]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 22 18:21:05 volumio node[876]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 22 18:21:05 volumio volumio[876]: *** WARNING *** Please fix your application to use the native API of Avahi! May 22 18:21:05 volumio node[876]: *** WARNING *** Please fix your application to use the native API of Avahi! May 22 18:21:05 volumio volumio[876]: *** WARNING *** For more information see May 22 18:21:05 volumio node[876]: *** WARNING *** For more information see May 22 18:21:05 volumio volumio[876]: info: Applying required configuration parameters for plugin volumiodiscovery May 22 18:21:05 volumio volumio[876]: info: Discovery: Started advertising with name: Volumio May 22 18:21:05 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 22 18:21:05 volumio volumio[876]: info: Loading plugin "outputs"... May 22 18:21:05 volumio volumio[876]: info: Loading plugin "albumart"... May 22 18:21:05 volumio volumio[876]: info: Plugin example_plugin is not enabled May 22 18:21:05 volumio volumio[876]: info: Loading plugin "inputs"... May 22 18:21:05 volumio volumio[876]: info: Loading plugin "updater_comm"... May 22 18:21:05 volumio volumio[876]: Forking 1 albumart workers May 22 18:21:05 volumio volumio[876]: info: Plugin mpdemulation is not enabled May 22 18:21:05 volumio volumio[876]: info: Loading plugin "rest_api"... May 22 18:21:05 volumio volumio[876]: info: Loading plugin "websocket"... May 22 18:21:05 volumio volumio[876]: info: Starting Socket.io Server version 2.3.0 May 22 18:21:05 volumio volumio[876]: info: Loading plugin "minidlna"... May 22 18:21:05 volumio volumio[876]: Starting albumart workers May 22 18:21:06 volumio volumio[876]: info: Applying required configuration parameters for plugin minidlna May 22 18:21:06 volumio volumio[876]: info: Loading plugin "music_services_shield"... May 22 18:21:06 volumio volumio[876]: info: Applying required configuration parameters for plugin music_services_shield May 22 18:21:06 volumio volumio[876]: info: Loading i18n strings for locale it May 22 18:21:06 volumio volumio[876]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 22 18:21:06 volumio volumio[876]: Updating browse sources language May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::initPlayerControls May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 18:21:06 volumio volumio[876]: Express server listening on port 3000 May 22 18:21:06 volumio volumio[876]: [Metrics] WebUI: 7s 181.25ms May 22 18:21:06 volumio volumio[876]: info: Setting Device type: x86 May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::resetVolumioState May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::getcurrentVolume May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioRetrievevolume May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:06 volumio volumio[876]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 22 18:21:06 volumio volumio[876]: info: Completed loading Core Plugins May 22 18:21:06 volumio volumio[876]: info: Preparing to generate the ALSA configuration file May 22 18:21:06 volumio volumio[876]: info: Volumio Network Manager: Network status updated: 0 May 22 18:21:06 volumio volumio[876]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 22 18:21:06 volumio volumio[876]: wlan0 Interface doesn't support scanning. May 22 18:21:06 volumio volumio[876]: info: Cannot use regular scanning, forcing with ap-force May 22 18:21:06 volumio sudo[1347]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 22 18:21:06 volumio sudo[1347]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:06 volumio sudo[1347]: pam_unix(sudo:session): session closed for user root May 22 18:21:06 volumio volumio[876]: command failed: No such device (-19) May 22 18:21:06 volumio volumio[876]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 22 18:21:06 volumio volumio[876]: command failed: No such device (-19) May 22 18:21:06 volumio volumio[876]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision May 22 18:21:06 volumio volumio[876]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 22 18:21:06 volumio volumio[876]: info: Reading ALSA contributions from plugins. May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:21:06 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::updateTrackBlock May 22 18:21:06 volumio volumio[876]: info: CorePlayQueue::getTrackBlock May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioRetrievevolume May 22 18:21:06 volumio volumio[876]: info: Reloading queue from file May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:21:06 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::setRepeat null single undefined May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:21:06 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::setRandom null May 22 18:21:06 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:21:06 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:21:06 volumio volumio[876]: info: Asound.conf file unchanged, so no further update is needed May 22 18:21:06 volumio volumio[876]: info: Output device has changed, restarting MPD May 22 18:21:06 volumio volumio[876]: info: Output device has changed, restarting Shairport Sync May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:06 volumio volumio[876]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 22 18:21:06 volumio volumio[876]: info: ___________ START PLUGINS ___________ May 22 18:21:06 volumio volumio[876]: info: ControllerMpd::onStart: Initializing MPD May 22 18:21:06 volumio volumio[876]: info: Creating MPD Configuration file May 22 18:21:06 volumio sudo[1364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 22 18:21:06 volumio sudo[1362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 22 18:21:06 volumio sudo[1362]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:06 volumio sudo[1364]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:06 volumio sudo[1362]: pam_unix(sudo:session): session closed for user root May 22 18:21:06 volumio systemd[1]: musicservicesshield.service: Succeeded. May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 18:21:06 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. May 22 18:21:06 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... May 22 18:21:06 volumio systemd[1]: Stopping Music Player Daemon... May 22 18:21:06 volumio sudo[1372]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 22 18:21:06 volumio sudo[1373]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 22 18:21:06 volumio volumio[876]: info: [1747930866700] CoreMusicLibrary::Adding element Server multimediali May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio sudo[1372]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:06 volumio sudo[1373]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:06 volumio sudo[1372]: pam_unix(sudo:session): session closed for user root May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:06 volumio volumio[876]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:06 volumio volumio[876]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 22 18:21:06 volumio volumio[876]: info: [1747930866767] CoreMusicLibrary::Adding element Last_100 May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 22 18:21:06 volumio volumio[876]: info: [1747930866768] CoreMusicLibrary::Adding element Webradio May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 18:21:06 volumio volumio[876]: info: Initializing BBC Radios May 22 18:21:06 volumio systemd[1]: mpd.service: Succeeded. May 22 18:21:06 volumio systemd[1]: Stopped Music Player Daemon. May 22 18:21:06 volumio systemd[1]: Starting Music Player Daemon... May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 18:21:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:06 volumio volumio[876]: info: Loading i18n strings for locale it May 22 18:21:06 volumio volumio[876]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 22 18:21:06 volumio sudo[1385]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 22 18:21:06 volumio sudo[1385]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:06 volumio sudo[1385]: pam_unix(sudo:session): session closed for user root May 22 18:21:07 volumio volumio[876]: info: Volumio Calling Home May 22 18:21:07 volumio sudo[1423]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh May 22 18:21:07 volumio sudo[1423]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:07 volumio mpd[1394]: May 22 18:21 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 22 18:21:07 volumio systemd[1]: Started Music Player Daemon. May 22 18:21:07 volumio sudo[1364]: pam_unix(sudo:session): session closed for user root May 22 18:21:07 volumio sudo[1373]: pam_unix(sudo:session): session closed for user root May 22 18:21:07 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... May 22 18:21:07 volumio volumio[876]: Unhandled rejection Error: No sockets available, cannot start. May 22 18:21:07 volumio volumio[876]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 22 18:21:07 volumio volumio[876]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 22 18:21:07 volumio volumio[876]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 22 18:21:07 volumio volumio[876]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 22 18:21:07 volumio volumio[876]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 22 18:21:07 volumio volumio[876]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 22 18:21:07 volumio volumio[876]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 22 18:21:07 volumio volumio[876]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 22 18:21:07 volumio volumio[876]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 22 18:21:07 volumio volumio[876]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 22 18:21:07 volumio volumio[876]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 22 18:21:07 volumio volumio[876]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 22 18:21:07 volumio volumio[876]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 22 18:21:07 volumio volumio[876]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 22 18:21:07 volumio volumio[876]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 22 18:21:07 volumio volumio[876]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 22 18:21:07 volumio volumio[876]: info: minidlna: Found miniDLNA version 1.2.1 May 22 18:21:07 volumio volumio[876]: info: minidlna: Starting minidlna.service May 22 18:21:07 volumio volumio[876]: info: MPD Permissions set May 22 18:21:07 volumio sudo[1450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service May 22 18:21:07 volumio sudo[1450]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:07 volumio systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. May 22 18:21:07 volumio sudo[1450]: pam_unix(sudo:session): session closed for user root May 22 18:21:07 volumio volumio[1438]: cset: --> shielding system active with May 22 18:21:07 volumio volumio[1438]: cset: "system" cpuset of CPUSPEC(1) with 178 tasks running May 22 18:21:07 volumio volumio[1438]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running May 22 18:21:07 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. May 22 18:21:07 volumio volumio[876]: error: MPD error: The expression evaluated to a falsy value: May 22 18:21:07 volumio volumio[876]: assert.ok(self.idling) May 22 18:21:07 volumio volumio[876]: error: The expression evaluated to a falsy value: May 22 18:21:07 volumio volumio[876]: assert.ok(self.idling) May 22 18:21:07 volumio volumio[876]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 May 22 18:21:07 volumio volumio[876]: info: MPD running with PID1394 May 22 18:21:07 volumio volumio[876]: ,establishing connection May 22 18:21:07 volumio systemd[1]: minidlna.service: Succeeded. May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 22 18:21:07 volumio sudo[1423]: pam_unix(sudo:session): session closed for user root May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:07 volumio volumio[876]: error: updateQueue error: null May 22 18:21:07 volumio volumio[876]: info: minidlna: systemctl start minidlna.service succeeded. May 22 18:21:07 volumio volumio[876]: info: Completed starting Core Plugins May 22 18:21:07 volumio volumio[876]: info: ------------------------------------------- May 22 18:21:07 volumio volumio[876]: info: ----- MyVolumio plugins startup ---- May 22 18:21:07 volumio volumio[876]: info: ------------------------------------------- May 22 18:21:07 volumio volumio[876]: info: [MyVolumio PluginManager] Fetching plans data.... May 22 18:21:07 volumio sudo[1480]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh May 22 18:21:07 volumio sudo[1480]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:07 volumio volumio[876]: error: updateQueue error: null May 22 18:21:07 volumio volumio[876]: info: Starting Shairport Sync May 22 18:21:07 volumio volumio[876]: info: Starting Shairport Sync May 22 18:21:07 volumio sudo[1484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 22 18:21:07 volumio volumio[876]: info: Starting Shairport Sync May 22 18:21:07 volumio sudo[1484]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:07 volumio sudo[1486]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 22 18:21:07 volumio sudo[1486]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:07 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 22 18:21:07 volumio systemd[1]: shairport-sync.service: Succeeded. May 22 18:21:07 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 22 18:21:07 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:07 volumio sudo[1491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 22 18:21:07 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:07 volumio sudo[1491]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:07 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 22 18:21:07 volumio sudo[1484]: pam_unix(sudo:session): session closed for user root May 22 18:21:08 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 22 18:21:08 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 22 18:21:08 volumio systemd[1]: shairport-sync.service: Succeeded. May 22 18:21:08 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 22 18:21:08 volumio volumio[876]: info: Shairport-Sync Started May 22 18:21:08 volumio volumio[876]: Error adding Membership: Error: addMembership EINVAL May 22 18:21:08 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 22 18:21:08 volumio systemd[1]: Reloading. May 22 18:21:08 volumio sudo[1486]: pam_unix(sudo:session): session closed for user root May 22 18:21:08 volumio volumio[876]: info: Shairport-Sync Started May 22 18:21:08 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 22 18:21:08 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 22 18:21:08 volumio systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 22 18:21:08 volumio sudo[1480]: pam_unix(sudo:session): session closed for user root May 22 18:21:08 volumio volumio[876]: info: succeeded May 22 18:21:08 volumio sudo[1491]: pam_unix(sudo:session): session closed for user root May 22 18:21:08 volumio volumio[876]: info: Shairport-Sync Started May 22 18:21:08 volumio volumio[876]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 18:21:09 volumio dhcpcd[763]: eth0: using IPv4LL address 169.254.166.224 May 22 18:21:09 volumio dhcpcd[763]: eth0: adding route to 169.254.0.0/16 May 22 18:21:09 volumio dhcpcd[763]: eth0: adding default route May 22 18:21:09 volumio avahi-daemon[667]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.166.224. May 22 18:21:09 volumio avahi-daemon[667]: New relevant interface eth0.IPv4 for mDNS. May 22 18:21:09 volumio avahi-daemon[667]: Registering new address record for 169.254.166.224 on eth0.IPv4. May 22 18:21:09 volumio volumio[876]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 May 22 18:21:09 volumio volumio-time-update[658]: volumio-time-update-util: Fetching time from Volumio... May 22 18:21:09 volumio sh[607]: eth0: using IPv4LL address 169.254.166.224 May 22 18:21:09 volumio sh[607]: eth0: adding route to 169.254.0.0/16 May 22 18:21:09 volumio sh[607]: eth0: adding default route May 22 18:21:09 volumio dhcpcd[654]: eth0: using IPv4LL address 169.254.166.224 May 22 18:21:09 volumio dhcpcd[654]: eth0: adding route to 169.254.0.0/16 May 22 18:21:09 volumio dhcpcd[654]: eth0: adding default route May 22 18:21:09 volumio sh[607]: forked to background, child pid 1535 May 22 18:21:09 volumio dhcpcd[654]: forked to background, child pid 1535 May 22 18:21:09 volumio sh[607]: eth0=eth0 May 22 18:21:09 volumio ifplugd(eth0)[841]: client: ifup: interface eth0 already configured May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::volumioGetVisibleSources May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:09 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::volumioGetQueue May 22 18:21:09 volumio volumio[876]: info: CoreStateMachine::getQueue May 22 18:21:09 volumio volumio[876]: info: CorePlayQueue::getQueue May 22 18:21:09 volumio volumio[876]: info: Listing playlists May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 18:21:09 volumio volumio[876]: info: Received Get System Info May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:09 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:09 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:09 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 22 18:21:09 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 18:21:09 volumio ifplugd(eth0)[841]: Program executed successfully. May 22 18:21:11 volumio ntpd[850]: Listen normally on 3 eth0 169.254.166.224:123 May 22 18:21:11 volumio ntpd[850]: new interface(s) found: waking up resolver May 22 18:21:11 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 18:21:11 volumio volumio[876]: info: Received Get System Info May 22 18:21:11 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:11 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:11 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:11 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:11 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:11 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:11 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 22 18:21:11 volumio systemd[1]: Started Samba NMB Daemon. May 22 18:21:11 volumio nmbd[800]: [2025/05/22 18:21:11.672077, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 22 18:21:11 volumio nmbd[800]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 22 18:21:11 volumio systemd[1]: Starting Samba Winbind Daemon... May 22 18:21:11 volumio winbindd[1562]: [2025/05/22 18:21:11.834759, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 22 18:21:11 volumio winbindd[1562]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 22 18:21:11 volumio winbindd[1562]: [2025/05/22 18:21:11.836472, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 22 18:21:11 volumio systemd[1]: Started Samba Winbind Daemon. May 22 18:21:11 volumio winbindd[1562]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 22 18:21:11 volumio systemd[1]: Starting Samba SMB Daemon... May 22 18:21:12 volumio volumio-remote-updater[664]: [2025-05-22 18:21:12] [connect] Successful connection May 22 18:21:12 volumio volumio-remote-updater[664]: [2025-05-22 18:21:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747930872 101 May 22 18:21:12 volumio volumio[876]: 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: 4 May 22 18:21:12 volumio smbd[1567]: [2025/05/22 18:21:12.113293, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 22 18:21:12 volumio systemd[1]: Started Samba SMB Daemon. May 22 18:21:12 volumio smbd[1567]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 22 18:21:12 volumio volumio[876]: info: Volumio Network Manager: Network status updated: 1 May 22 18:21:13 volumio sudo[1590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 18:21:13 volumio sudo[1590]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:13 volumio sudo[1592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 18:21:13 volumio sudo[1590]: pam_unix(sudo:session): session closed for user root May 22 18:21:13 volumio sudo[1592]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:13 volumio sudo[1592]: pam_unix(sudo:session): session closed for user root May 22 18:21:13 volumio sudo[1598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 22 18:21:13 volumio sudo[1598]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:13 volumio systemd[1]: Started UPnP Renderer front-end to MPD. May 22 18:21:13 volumio sudo[1598]: pam_unix(sudo:session): session closed for user root May 22 18:21:13 volumio volumio[876]: info: Upmpdcli Daemon Started May 22 18:21:13 volumio volumio[1600]: Generating RSA private key, 4096 bit long modulus (2 primes) May 22 18:21:13 volumio volumio[1600]: ..................................++++ May 22 18:21:15 volumio volumio[1600]: .......................................................................................................................................................................................++++ May 22 18:21:15 volumio volumio[1600]: e is 65537 (0x010001) May 22 18:21:15 volumio volumio[1600]: writing RSA key May 22 18:21:15 volumio dhcpcd[763]: eth0: offered 192.168.8.194 from 192.168.8.1 May 22 18:21:15 volumio dhcpcd[763]: eth0: probing address 192.168.8.194/24 May 22 18:21:16 volumio dhcpcd[1535]: eth0: offered 192.168.8.194 from 192.168.8.1 May 22 18:21:16 volumio dhcpcd[1535]: eth0: probing address 192.168.8.194/24 May 22 18:21:17 volumio volumio[876]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.812&uuid=d6b17d201db73150280d77250758cea7" http://updates.volumio.org/downloader-v1/track-device May 22 18:21:17 volumio volumio[876]: curl: (6) Could not resolve host: updates.volumio.org May 22 18:21:17 volumio volumio[876]: retrying in 5 seconds, trial 0 May 22 18:21:17 volumio volumio[876]: info: Volumio Calling Home May 22 18:21:19 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 22 18:21:21 volumio dhcpcd[763]: eth0: leased 192.168.8.194 for 86400 seconds May 22 18:21:21 volumio dhcpcd[763]: eth0: adding route to 192.168.8.0/24 May 22 18:21:21 volumio dhcpcd[763]: eth0: changing default route via 192.168.8.1 May 22 18:21:21 volumio dhcpcd[763]: eth0: dhcp_envoption 213: Operation not supported May 22 18:21:21 volumio dhcpcd[763]: eth0: dhcp_envoption 213: Operation not supported May 22 18:21:21 volumio avahi-daemon[667]: Registering new address record for 192.168.8.194 on eth0.IPv4. May 22 18:21:21 volumio dhcpcd[1535]: eth0: deleted default route May 22 18:21:21 volumio systemd[1]: Stopping Network Time Service... May 22 18:21:21 volumio ntpd[850]: ntpd exiting on signal 15 (Terminated) May 22 18:21:21 volumio systemd[1]: ntp.service: Succeeded. May 22 18:21:21 volumio systemd[1]: Stopped Network Time Service. May 22 18:21:21 volumio systemd[1]: Starting Network Time Service... May 22 18:21:21 volumio ntpd[1855]: ntpd 4.2.8p12@1.3728-o (1): Starting May 22 18:21:21 volumio ntpd[1855]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 May 22 18:21:21 volumio systemd[1]: Started Network Time Service. May 22 18:21:21 volumio dhcpcd[763]: eth0: deleting route to 169.254.0.0/16 May 22 18:21:21 volumio dhcpcd[1535]: eth0: deleted route to 169.254.0.0/16 May 22 18:21:21 volumio dhcpcd[1535]: eth0: adding route to 169.254.0.0/16 May 22 18:21:21 volumio dhcpcd[1535]: if_route (ADD): Invalid argument May 22 18:21:21 volumio dhcpcd[1535]: eth0: adding default route May 22 18:21:21 volumio dhcpcd[1535]: if_route (ADD): Invalid argument May 22 18:21:21 volumio avahi-daemon[667]: Withdrawing address record for 169.254.166.224 on eth0. May 22 18:21:21 volumio avahi-daemon[667]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.166.224. May 22 18:21:21 volumio avahi-daemon[667]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.8.194. May 22 18:21:21 volumio ntpd[1861]: proto: precision = 0.051 usec (-24) May 22 18:21:21 volumio ntpd[1861]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 22 18:21:21 volumio ntpd[1861]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 22 18:21:21 volumio ntpd[1861]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 877 days ago May 22 18:21:21 volumio ntpd[1861]: Listen and drop on 0 v6wildcard [::]:123 May 22 18:21:21 volumio ntpd[1861]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 22 18:21:21 volumio ntpd[1861]: Listen normally on 2 lo 127.0.0.1:123 May 22 18:21:21 volumio ntpd[1861]: Listen normally on 3 eth0 192.168.8.194:123 May 22 18:21:21 volumio ntpd[1861]: Listening on routing socket on fd #20 for interface updates May 22 18:21:21 volumio ntpd[1861]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 22 18:21:21 volumio ntpd[1861]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 22 18:21:21 volumio dhcpcd[1535]: eth0: leased 192.168.8.194 for 86400 seconds May 22 18:21:21 volumio dhcpcd[1535]: eth0: adding route to 192.168.8.0/24 May 22 18:21:21 volumio dhcpcd[1535]: eth0: adding default route via 192.168.8.1 May 22 18:21:21 volumio dhcpcd[1535]: eth0: adding route to 169.254.0.0/16 May 22 18:21:21 volumio dhcpcd[1535]: if_route (ADD): Invalid argument May 22 18:21:21 volumio dhcpcd[1535]: eth0: dhcp_envoption 213: Operation not supported May 22 18:21:21 volumio dhcpcd[1535]: eth0: dhcp_envoption 213: Operation not supported May 22 18:21:21 volumio systemd[1]: Stopping Network Time Service... May 22 18:21:21 volumio ntpd[1861]: ntpd exiting on signal 15 (Terminated) May 22 18:21:21 volumio systemd[1]: ntp.service: Succeeded. May 22 18:21:21 volumio systemd[1]: Stopped Network Time Service. May 22 18:21:21 volumio systemd[1]: Starting Network Time Service... May 22 18:21:21 volumio ntpd[1909]: ntpd 4.2.8p12@1.3728-o (1): Starting May 22 18:21:21 volumio ntpd[1909]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 May 22 18:21:21 volumio systemd[1]: Started Network Time Service. May 22 18:21:21 volumio ntpd[1915]: proto: precision = 0.050 usec (-24) May 22 18:21:21 volumio kernel: dhcpcd[1535]: segfault at 28 ip 00005564897656b6 sp 00007ffdcb4f3ee0 error 4 in dhcpcd[55648974f000+32000] likely on CPU 1 (core 1, socket 0) May 22 18:21:21 volumio kernel: Code: 20 0f 11 45 18 0f 11 45 28 0f 11 45 38 0f 11 45 48 c7 04 24 18 00 00 00 66 89 4c 24 06 40 80 ff 14 0f 84 7d 00 00 00 8b 7e 14 <8b> 40 28 c6 44 24 10 02 89 44 24 14 e8 29 7b 00 00 4c 89 e1 ba 02 May 22 18:21:21 volumio ntpd[1915]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 22 18:21:21 volumio ntpd[1915]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 22 18:21:21 volumio ntpd[1915]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 877 days ago May 22 18:21:21 volumio ntpd[1915]: Listen and drop on 0 v6wildcard [::]:123 May 22 18:21:21 volumio ntpd[1915]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 22 18:21:21 volumio ntpd[1915]: Listen normally on 2 lo 127.0.0.1:123 May 22 18:21:21 volumio ntpd[1915]: Listen normally on 3 eth0 192.168.8.194:123 May 22 18:21:21 volumio ntpd[1915]: Listening on routing socket on fd #20 for interface updates May 22 18:21:21 volumio ntpd[1915]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 22 18:21:21 volumio ntpd[1915]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 22 18:21:22 volumio volumio[876]: info: Volumio called home May 22 18:21:23 volumio ntpd[1915]: Soliciting pool server 151.22.209.90 May 22 18:21:23 volumio systemd[1]: systemd-fsckd.service: Succeeded. May 22 18:21:23 volumio ntpd[1915]: Soliciting pool server 212.6.50.243 May 22 18:21:23 volumio ntpd[1915]: Soliciting pool server 162.159.200.1 May 22 18:21:24 volumio volumio-time-update[658]: volumio-time-update-util: Date not found in response May 22 18:21:24 volumio volumio-time-update[658]: volumio-time-update-util: Retrying in 5 seconds... May 22 18:21:24 volumio ntpd[1915]: Soliciting pool server 89.46.74.148 May 22 18:21:24 volumio ntpd[1915]: Soliciting pool server 93.94.88.51 May 22 18:21:24 volumio ntpd[1915]: Soliciting pool server 185.157.229.254 May 22 18:21:25 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 18:21:25 volumio volumio[876]: info: Received Get System Info May 22 18:21:25 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:25 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:25 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:25 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:25 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:25 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:25 volumio volumio[876]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 May 22 18:21:25 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 22 18:21:25 volumio volumio[876]: info: Adding plugin bluetooth to MyMusic Plugins May 22 18:21:25 volumio volumio[876]: info: Adding plugin multiroom to MyMusic Plugins May 22 18:21:25 volumio volumio[876]: info: Adding plugin metavolumio to MyMusic Plugins May 22 18:21:25 volumio volumio[876]: info: Adding plugin cd_controller to MyMusic Plugins May 22 18:21:25 volumio volumio[876]: info: Adding plugin qobuzconnect to MyMusic Plugins May 22 18:21:25 volumio ntpd[1915]: Soliciting pool server 81.56.230.156 May 22 18:21:25 volumio ntpd[1915]: Soliciting pool server 195.32.70.195 May 22 18:21:25 volumio ntpd[1915]: Soliciting pool server 212.45.144.206 May 22 18:21:25 volumio volumio[876]: info: Adding plugin smart_inputs to MyMusic Plugins May 22 18:21:25 volumio volumio[876]: info: Adding plugin tidalconnect to MyMusic Plugins May 22 18:21:25 volumio volumio[876]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 22 18:21:26 volumio ntpd[1915]: Soliciting pool server 93.94.88.50 May 22 18:21:26 volumio volumio[876]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 22 18:21:26 volumio volumio[876]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 22 18:21:26 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:26 volumio volumio[876]: info: Starting MyVolumio Remote Streaming Endpoints May 22 18:21:26 volumio volumio[876]: info: MyVolumio login type: Token May 22 18:21:26 volumio volumio[876]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 22 18:21:26 volumio volumio[876]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 22 18:21:26 volumio volumio[876]: info: Starting Streaming Service Transparent Proxy May 22 18:21:26 volumio volumio[876]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 22 18:21:26 volumio volumio[876]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 22 18:21:26 volumio volumio[876]: info: Streaming services startup May 22 18:21:26 volumio volumio[876]: info: Starting Streaming Daemon May 22 18:21:26 volumio sudo[1950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 22 18:21:26 volumio sudo[1950]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:26 volumio volumio[876]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 22 18:21:26 volumio sudo[1950]: pam_unix(sudo:session): session closed for user root May 22 18:21:26 volumio volumio[876]: error: Cannot start Volumio Streaming Daemon May 22 18:21:26 volumio volumio[876]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 22 18:21:26 volumio volumio[876]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 22 18:21:26 volumio ntpd[1915]: Soliciting pool server 85.199.214.99 May 22 18:21:26 volumio ntpd[1915]: Soliciting pool server 2.234.152.249 May 22 18:21:26 volumio ntpd[1915]: Soliciting pool server 185.19.184.35 May 22 18:21:26 volumio volumio[876]: STREAMING PROXY: Starting server on port 3245 May 22 18:21:26 volumio volumio[876]: Node JS runtime: 14 May 22 18:21:27 volumio volumio[876]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 22 18:21:27 volumio ntpd[1915]: Soliciting pool server 37.247.53.178 May 22 18:21:27 volumio ntpd[1915]: Soliciting pool server 2603:c027:2:c801:1979::1 May 22 18:21:28 volumio volumio[876]: info: MyVolumio token set successfully May 22 18:21:28 volumio volumio[876]: info: MYVOLUMIO: Adding device May 22 18:21:28 volumio volumio[876]: info: MYVOLUMIO: Evaluating Server May 22 18:21:28 volumio volumio[876]: info: MyVolumio status changed May 22 18:21:28 volumio volumio[876]: info: Streaming services startup May 22 18:21:28 volumio volumio[876]: info: Starting Streaming Daemon May 22 18:21:28 volumio volumio[876]: info: Removing browser output: myVolumio user plan is not superstar May 22 18:21:28 volumio volumio[876]: info: Removing audio output: May 22 18:21:28 volumio sudo[1981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 22 18:21:28 volumio volumio[876]: info: Stoppping Tunnel 1 May 22 18:21:28 volumio sudo[1981]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:28 volumio sudo[1981]: pam_unix(sudo:session): session closed for user root May 22 18:21:28 volumio volumio[876]: error: Cannot start Volumio Streaming Daemon May 22 18:21:28 volumio sudo[1984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 22 18:21:28 volumio volumio[876]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 22 18:21:28 volumio volumio[876]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 22 18:21:28 volumio sudo[1984]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:28 volumio sudo[1984]: pam_unix(sudo:session): session closed for user root May 22 18:21:28 volumio volumio[876]: info: Remote SSH Stopped May 22 18:21:28 volumio volumio[876]: info: Setting Geolocation for MyVolumio to eu4 May 22 18:21:28 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:28 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:28 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:29 volumio volumio[876]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 22 18:21:29 volumio volumio-time-update[658]: volumio-time-update-util: Fetching time from Volumio... May 22 18:21:29 volumio volumio[876]: info: Updating MyVolumio device info May 22 18:21:29 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:29 volumio volumio-time-update[658]: volumio-time-update-util: Setting system time to: 2025-05-22 18:21:30 May 22 18:21:29 volumio sudo[1991]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-05-22 18:21:30 May 22 18:21:29 volumio sudo[1991]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:29 volumio dbus-daemon[671]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.15' (uid=0 pid=1992 comm="timedatectl set-time 2025-05-22 18:21:30 ") May 22 18:21:29 volumio systemd[1]: Starting Time & Date Service... May 22 18:21:29 volumio dbus-daemon[671]: [system] Successfully activated service 'org.freedesktop.timedate1' May 22 18:21:29 volumio systemd[1]: Started Time & Date Service. May 22 18:21:30 volumio systemd-timedated[1993]: Changed local time to Thu May 22 18:21:30 2025 May 22 18:21:30 volumio sudo[1991]: pam_unix(sudo:session): session closed for user root May 22 18:21:30 volumio volumio-time-update[658]: volumio-time-update-util: System time updated successfully. May 22 18:21:30 volumio systemd[1]: Started Volumio Time Update Utility. May 22 18:21:30 volumio systemd[1]: Reached target Multi-User System. May 22 18:21:30 volumio systemd[1]: Reached target Graphical Interface. May 22 18:21:30 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... May 22 18:21:30 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 22 18:21:30 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. May 22 18:21:30 volumio systemd[1]: Startup finished in 18.893s (firmware) + 2.722s (loader) + 8.891s (kernel) + 40.974s (userspace) = 1min 11.482s. May 22 18:21:30 volumio volumio[876]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 22 18:21:32 volumio ntpd[1915]: receive: Unexpected origin timestamp 0xebd9cd8b.ecbde2d0 does not match aorg 0000000000.00000000 from server@185.19.184.35 xmt 0xebd9cd8c.3130cc43 May 22 18:21:32 volumio ntpd[1915]: receive: Unexpected origin timestamp 0xebd9cd8b.ecbf49fe does not match aorg 0000000000.00000000 from server@151.22.209.90 xmt 0xebd9cd8c.31d4d11e May 22 18:21:32 volumio ntpd[1915]: receive: Unexpected origin timestamp 0xebd9cd8b.ecbefcd4 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xebd9cd8c.326df89a May 22 18:21:32 volumio ntpd[1915]: receive: Unexpected origin timestamp 0xebd9cd8b.ecbe70bd does not match aorg 0000000000.00000000 from server@195.32.70.195 xmt 0xebd9cd8c.3436a832 May 22 18:21:32 volumio ntpd[1915]: receive: Unexpected origin timestamp 0xebd9cd8b.ecbc7cf0 does not match aorg 0000000000.00000000 from server@85.199.214.99 xmt 0xebd9cd8c.31ae8885 May 22 18:21:32 volumio ntpd[1915]: receive: Unexpected origin timestamp 0xebd9cd8b.ecbe2cab does not match aorg 0000000000.00000000 from server@81.56.230.156 xmt 0xebd9cd8c.325b530c May 22 18:21:33 volumio volumio[876]: info: MYVOLUMIO: Adding device May 22 18:21:33 volumio volumio[876]: info: MYVOLUMIO: Evaluating Server May 22 18:21:34 volumio volumio[876]: info: Setting Geolocation for MyVolumio to eu3 May 22 18:21:34 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:34 volumio volumio[876]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 22 18:21:34 volumio systemd[1]: systemd-hostnamed.service: Succeeded. May 22 18:21:35 volumio volumio[876]: info: Updating MyVolumio device info May 22 18:21:35 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:35 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:35 volumio volumio[876]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 22 18:21:37 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 18:21:37 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:37 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 18:21:37 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 22 18:21:37 volumio volumio-remote-updater[664]: No test mode May 22 18:21:37 volumio volumio-remote-updater[664]: No alpha test mode May 22 18:21:37 volumio volumio[876]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 22 18:21:37 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 22 18:21:41 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 18:21:41 volumio volumio[876]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 22 18:21:41 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:41 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::volumioGetBrowseSources May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 18:21:46 volumio volumio[876]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 22 18:21:46 volumio volumio[876]: info: Completed starting MyVolumio Plugin May 22 18:21:46 volumio volumio[876]: [Metrics] CommandRouter: 46s 486.24ms May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::volumiosetStartupVolume May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 18:21:46 volumio volumio[876]: info: VolumeController:: Setting startup Volume 50 May 22 18:21:46 volumio volumio[876]: info: VolumeController::SetAlsaVolume50 May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:21:46 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:21:46 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 18:21:46 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:21:47 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 22 18:21:47 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 22 18:21:47 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 22 18:21:50 volumio volumio[876]: verbose: New Socket.io Connection to 192.168.8.194 from 192.168.8.184 UA: Mozilla/5.0 (Linux; Android 15; A015 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::volumioGetVisibleSources May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:50 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 18:21:50 volumio volumio[876]: info: Received Get System Info May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:50 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:50 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:50 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:50 volumio volumio[876]: info: Listing playlists May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::volumioGetQueue May 22 18:21:50 volumio volumio[876]: info: CoreStateMachine::getQueue May 22 18:21:50 volumio volumio[876]: info: CorePlayQueue::getQueue May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:50 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:50 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:50 volumio volumio[876]: verbose: New Socket.io Connection to 192.168.8.194:3000 from 192.168.8.184 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:50 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 22 18:21:50 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 22 18:21:51 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:51 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:51 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:51 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:51 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:51 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:53 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:53 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:53 volumio volumio[876]: verbose: New Socket.io Connection to 192.168.8.194:3000 from 192.168.8.184 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 May 22 18:21:53 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:53 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:53 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 22 18:21:53 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 22 18:21:53 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:53 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:53 volumio volumio[876]: info: BOOT COMPLETED May 22 18:21:54 volumio sudo[2066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 18:21:54 volumio sudo[2066]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:54 volumio sudo[2066]: pam_unix(sudo:session): session closed for user root May 22 18:21:54 volumio sudo[2069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 18:21:54 volumio sudo[2069]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:54 volumio sudo[2069]: pam_unix(sudo:session): session closed for user root May 22 18:21:54 volumio volumio[876]: verbose: New Socket.io Connection to 192.168.8.194 from 192.168.8.184 UA: Mozilla/5.0 (Linux; Android 15; A015 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 22 18:21:54 volumio sudo[2074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 18:21:54 volumio sudo[2074]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:54 volumio sudo[2074]: pam_unix(sudo:session): session closed for user root May 22 18:21:54 volumio sudo[2076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 18:21:54 volumio sudo[2076]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 18:21:54 volumio sudo[2076]: pam_unix(sudo:session): session closed for user root May 22 18:21:54 volumio volumio[876]: verbose: New Socket.io Connection to 192.168.8.194 from 192.168.8.184 UA: Mozilla/5.0 (Linux; Android 15; A015 Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::volumioGetVisibleSources May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:55 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 18:21:55 volumio volumio[876]: info: Received Get System Info May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:55 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:55 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:55 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:55 volumio volumio[876]: info: Listing playlists May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 18:21:55 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 18:21:56 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 18:21:56 volumio volumio[876]: info: Received Get System Info May 22 18:21:56 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:56 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:56 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:56 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:56 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:56 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:56 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 22 18:21:57 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 18:21:57 volumio volumio[876]: info: Received Get System Info May 22 18:21:57 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:21:57 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:21:57 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:21:57 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:21:57 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:21:57 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 18:21:58 volumio volumio[876]: info: Retrieving Cloud Streaming UI May 22 18:21:58 volumio volumio[876]: info: Getting Tidal Cloud Configuration May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 18:21:58 volumio volumio[876]: info: Getting Qobuz Cloud Configuration May 22 18:21:58 volumio volumio[876]: info: Asking plugin for UI Config May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 18:21:58 volumio volumio[876]: info: Getting Spotify Cloud Configuration May 22 18:21:58 volumio volumio[876]: info: Asking plugin for UI Config May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 18:21:58 volumio volumio[876]: info: Saving Spotify Acccount May 22 18:21:58 volumio volumio[876]: info: Got Tidal Cloud Configuration May 22 18:21:58 volumio volumio[876]: info: Got it May 22 18:21:58 volumio volumio[876]: info: Got it May 22 18:21:58 volumio volumio[876]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 18:21:58 volumio volumio[876]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::volumioGetBrowseSources May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::volumioGetBrowseSources May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::volumioGetBrowseSources May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 18:21:58 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 22 18:22:00 volumio systemd[1]: systemd-timedated.service: Succeeded. May 22 18:22:00 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand rescan May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:00 volumio volumio[876]: info: May 22 18:22:00 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:00 volumio volumio[876]: info: sendMpdCommand rescan took 2 milliseconds May 22 18:22:00 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:00 volumio volumio[876]: info: May 22 18:22:00 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:00 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:00 volumio volumio[876]: info: May 22 18:22:00 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:00 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:00 volumio volumio[876]: info: sendMpdCommand status took 26 milliseconds May 22 18:22:00 volumio volumio[876]: info: sendMpdCommand status took 16 milliseconds May 22 18:22:00 volumio volumio[876]: info: sendMpdCommand status took 15 milliseconds May 22 18:22:00 volumio volumio[876]: info: sendMpdCommand status took 13 milliseconds May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:00 volumio volumio[876]: info: Command Router : Notfying DB Updatetrue May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:00 volumio volumio[876]: info: Command Router : Notfying DB Updatetrue May 22 18:22:00 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:00 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: info: Command Router : Notfying DB Updatetrue May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 415ms May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 414ms May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 404ms May 22 18:22:01 volumio volumio[876]: info: MPD Database updated - AlbumList cache refreshed May 22 18:22:01 volumio volumio[876]: info: May 22 18:22:01 volumio volumio[876]: ---------------------------- MPD announces state update: database May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: May 22 18:22:01 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: MPD Database updated - AlbumList cache refreshed May 22 18:22:01 volumio volumio[876]: info: May 22 18:22:01 volumio volumio[876]: ---------------------------- MPD announces state update: database May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: May 22 18:22:01 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: MPD Database updated - AlbumList cache refreshed May 22 18:22:01 volumio volumio[876]: info: May 22 18:22:01 volumio volumio[876]: ---------------------------- MPD announces state update: database May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: May 22 18:22:01 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 15 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 12 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 12 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 10 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 10 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 10 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 9 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 9 milliseconds May 22 18:22:01 volumio volumio[876]: info: sendMpdCommand status took 9 milliseconds May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: info: Command Router : Notfying DB Updatefalse May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: info: Command Router : Notfying DB Updatefalse May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: info: Command Router : Notfying DB Updatefalse May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:01 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: No code May 22 18:22:01 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:01 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:01 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 171ms May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 173ms May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 170ms May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 174ms May 22 18:22:01 volumio volumio[876]: info: ------------------------------ 173ms May 22 18:22:02 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand update May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: May 22 18:22:03 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand update took 4 milliseconds May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: May 22 18:22:03 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: May 22 18:22:03 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 7 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 4 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 1 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 0 milliseconds May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: Command Router : Notfying DB Updatetrue May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: Command Router : Notfying DB Updatetrue May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: Command Router : Notfying DB Updatetrue May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:03 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: No code May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:03 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: No code May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:03 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: No code May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: ------------------------------ 262ms May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: May 22 18:22:03 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: May 22 18:22:03 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: May 22 18:22:03 volumio volumio[876]: ---------------------------- MPD announces state update: update May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::getState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::sendMpdCommand status May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 8 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 8 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 8 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 10 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 11 milliseconds May 22 18:22:03 volumio volumio[876]: info: sendMpdCommand status took 11 milliseconds May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: Command Router : Notfying DB Updatefalse May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: Command Router : Notfying DB Updatefalse May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: Command Router : Notfying DB Updatefalse May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::Close All Modals sent May 22 18:22:03 volumio volumio[876]: verbose: ControllerMpd::parseState May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:03 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: No code May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:03 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: No code May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: ControllerMpd::pushState May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::servicePushState May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 22 18:22:03 volumio volumio[876]: verbose: CURRENT POSITION 0 May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState stateService stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::syncState currentStatus stop May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: No code May 22 18:22:03 volumio volumio[876]: info: CoreStateMachine::pushState May 22 18:22:03 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:03 volumio volumio[876]: info: CoreCommandRouter::volumioPushState May 22 18:22:03 volumio volumio[876]: info: ------------------------------ 169ms May 22 18:22:03 volumio volumio[876]: info: ------------------------------ 170ms May 22 18:22:03 volumio volumio[876]: info: ------------------------------ 173ms May 22 18:22:04 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 22 18:22:06 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 18:22:10 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 18:22:13 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 18:22:13 volumio volumio[876]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 22 18:22:13 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 22 18:22:13 volumio volumio[876]: info: Received Get System Version May 22 18:22:13 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 18:22:13 volumio volumio[876]: info: Received Get System Info May 22 18:22:13 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 18:22:13 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 18:22:13 volumio volumio[876]: info: Discovery: Getting this device information May 22 18:22:13 volumio volumio[876]: info: CoreCommandRouter::volumioGetState May 22 18:22:13 volumio volumio[876]: info: CorePlayQueue::getTrack 0 May 22 18:22:13 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 18:22:14 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 18:22:18 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 18:22:19 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares May 22 18:22:19 volumio volumio[876]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService May 22 18:22:19 volumio volumio[876]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 18:22:19 volumio volumio[876]: Error: getaddrinfo -3007 May 22 18:22:19 volumio volumio[876]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) May 22 18:22:19 volumio volumio[876]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) May 22 18:22:19 volumio volumio[876]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { May 22 18:22:19 volumio volumio[876]: code: -3007, May 22 18:22:19 volumio volumio[876]: errno: -3007, May 22 18:22:19 volumio volumio[876]: syscall: 'getaddrinfo' May 22 18:22:19 volumio volumio[876]: } May 22 18:22:19 volumio volumio[876]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 18:22:19 volumio sudo[2199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-22 18:21 May 22 18:22:19 volumio sudo[2199]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:50:12 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="39b0f8c200b2dcadf117e189b4b3632d"