Apr 14 14:22:00 volumio2 volumio[1064]: info: ------------------------------------------- Apr 14 14:22:00 volumio2 volumio[1064]: info: ----- Volumio3 ---- Apr 14 14:22:00 volumio2 volumio[1064]: info: ------------------------------------------- Apr 14 14:22:00 volumio2 volumio[1064]: info: ----- System startup ---- Apr 14 14:22:00 volumio2 volumio[1064]: info: ------------------------------------------- Apr 14 14:22:00 volumio2 ntpd[999]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:00 volumio2 ntpd[999]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Apr 14 14:22:00 volumio2 ntpd[999]: DNS: dns_check: DNS error: -11, System error Apr 14 14:22:00 volumio2 ntpd[999]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Apr 14 14:22:00 volumio2 volumio[1064]: info: MYVOLUMIO Environment detected Apr 14 14:22:00 volumio2 volumio[1064]: info: Plugin folders cleanup Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning into folder /volumio/app/plugins/ Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning category audio_interface Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning category miscellanea Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning category music_service Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning category plugins.json Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning category system_controller Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning category user_interface Apr 14 14:22:00 volumio2 volumio[1064]: info: Scanning into folder /data/plugins/ Apr 14 14:22:00 volumio2 volumio[1064]: info: Plugin folders cleanup completed Apr 14 14:22:00 volumio2 volumio[1064]: info: ------------------------------------------- Apr 14 14:22:00 volumio2 volumio[1064]: info: ----- Core plugins startup ---- Apr 14 14:22:00 volumio2 volumio[1064]: info: ------------------------------------------- Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 14:22:00 volumio2 volumio[1064]: info: Adding plugin upnp to MyMusic Plugins Apr 14 14:22:00 volumio2 volumio[1064]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 14:22:00 volumio2 volumio[1064]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugins from folder /data/plugins/ Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "system"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "appearance"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "network"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Refreshing Cached IP Addresses Apr 14 14:22:00 volumio2 avahi-daemon[755]: Service "Volumio2" (/services/volumio.service) successfully established. Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "services"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "volumio5onboarding"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "alsa_controller"... Apr 14 14:22:00 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "wizard"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "networkfs"... Apr 14 14:22:00 volumio2 sudo[1211]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 14:22:00 volumio2 sudo[1198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 14:22:00 volumio2 sudo[1200]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 14:22:00 volumio2 sudo[1211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:00 volumio2 sudo[1200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:00 volumio2 sudo[1198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:00 volumio2 sudo[1198]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:00 volumio2 volumio[1064]: info: Starting Udev Watcher for removable devices Apr 14 14:22:00 volumio2 sudo[1211]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:00 volumio2 sudo[1200]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:00 volumio2 volumio[1064]: info: Ignoring mount for partition: boot Apr 14 14:22:00 volumio2 volumio[1064]: info: Ignoring mount for partition: volumio Apr 14 14:22:00 volumio2 volumio[1064]: info: Ignoring mount for partition: volumio_data Apr 14 14:22:00 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "volumio_command_line_client"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "upnp"... Apr 14 14:22:00 volumio2 volumio[1064]: info: [1776169320596] Starting Upmpd Daemon Apr 14 14:22:00 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "my_music"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "mpd"... Apr 14 14:22:00 volumio2 volumio[1064]: info: Loading plugin "upnp_browser"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Starting UPNP Browser Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "alarm-clock"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "airplay_emulation"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Starting Shairport Sync Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "last_100"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "webradio"... Apr 14 14:22:01 volumio2 ntpd[999]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:01 volumio2 ntpd[999]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Apr 14 14:22:01 volumio2 ntpd[999]: DNS: dns_check: DNS error: -11, System error Apr 14 14:22:01 volumio2 ntpd[999]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "i2s_dacs"... Apr 14 14:22:01 volumio2 volumio[1064]: info: I2S DAC not set, start Auto-detection Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "volumiodiscovery"... Apr 14 14:22:01 volumio2 volumio[1064]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 14:22:01 volumio2 volumio[1064]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 14:22:01 volumio2 volumio[1064]: *** WARNING *** For more information see Apr 14 14:22:01 volumio2 volumio[1064]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 14:22:01 volumio2 node[1064]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 14:22:01 volumio2 volumio[1064]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 14:22:01 volumio2 volumio[1064]: *** WARNING *** For more information see Apr 14 14:22:01 volumio2 node[1064]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 14:22:01 volumio2 node[1064]: *** WARNING *** For more information see Apr 14 14:22:01 volumio2 node[1064]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 14:22:01 volumio2 node[1064]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 14:22:01 volumio2 node[1064]: *** WARNING *** For more information see Apr 14 14:22:01 volumio2 volumio[1064]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 14:22:01 volumio2 volumio[1064]: info: Discovery: Started advertising with name: Volumio2 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "outputs"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "albumart"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Plugin example_plugin is not enabled Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "inputs"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "updater_comm"... Apr 14 14:22:01 volumio2 volumio[1317]: Forking 3 albumart workers Apr 14 14:22:01 volumio2 volumio[1064]: info: Plugin mpdemulation is not enabled Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "rest_api"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading plugin "websocket"... Apr 14 14:22:01 volumio2 volumio[1064]: info: Starting Socket.io Server version 1.7.4 Apr 14 14:22:01 volumio2 volumio[1064]: info: Loading i18n strings for locale fr Apr 14 14:22:01 volumio2 volumio[1064]: Updating browse sources language Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:22:01 volumio2 volumio[1327]: Starting albumart workers Apr 14 14:22:01 volumio2 volumio[1329]: Starting albumart workers Apr 14 14:22:01 volumio2 volumio[1328]: Starting albumart workers Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::initPlayerControls Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: Express server listening on port 3000 Apr 14 14:22:01 volumio2 volumio[1064]: [Metrics] WebUI: 1s 500.70ms Apr 14 14:22:01 volumio2 volumio[1064]: info: Setting Device type: x86 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreStateMachine::resetVolumioState Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreStateMachine::getcurrentVolume Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:22:01 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 14 14:22:01 volumio2 volumio[1064]: info: Completed loading Core Plugins Apr 14 14:22:01 volumio2 volumio[1064]: info: Preparing to generate the ALSA configuration file Apr 14 14:22:01 volumio2 volumio[1064]: info: Volumio Network Manager: Network status updated: 0 Apr 14 14:22:01 volumio2 volumio[1064]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 14 14:22:01 volumio2 volumio[1064]: wlan0 Interface doesn't support scanning. Apr 14 14:22:01 volumio2 volumio[1064]: info: Cannot use regular scanning, forcing with ap-force Apr 14 14:22:01 volumio2 sudo[1379]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 14 14:22:01 volumio2 sudo[1379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 sudo[1379]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 volumio[1064]: command failed: No such device (-19) Apr 14 14:22:01 volumio2 volumio[1064]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 14 14:22:01 volumio2 volumio[1064]: command failed: No such device (-19) Apr 14 14:22:01 volumio2 volumio[1064]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 14 14:22:01 volumio2 volumio[1064]: info: Reloading queue from file Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreStateMachine::setRepeat null single undefined Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:22:01 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreStateMachine::setRandom null Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:22:01 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:22:01 volumio2 volumio[1064]: info: Asound.conf file written Apr 14 14:22:01 volumio2 sudo[1399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 14 14:22:01 volumio2 sudo[1399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 sudo[1399]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 volumio[1064]: info: Output device has changed, restarting MPD Apr 14 14:22:01 volumio2 volumio[1064]: info: Output device has changed, restarting Shairport Sync Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:01 volumio2 sudo[1411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 14:22:01 volumio2 sudo[1411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 sudo[1413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 14:22:01 volumio2 sudo[1413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 sudo[1411]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 volumio[1064]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 14:22:01 volumio2 volumio[1064]: info: ___________ START PLUGINS ___________ Apr 14 14:22:01 volumio2 sudo[1421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 14 14:22:01 volumio2 sudo[1421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 volumio[1064]: info: ControllerMpd::onStart: Initializing MPD Apr 14 14:22:01 volumio2 volumio[1064]: info: Creating MPD Configuration file Apr 14 14:22:01 volumio2 sudo[1426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 14:22:01 volumio2 sudo[1426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 14:22:01 volumio2 sudo[1424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 14:22:01 volumio2 volumio[1064]: info: [1776169321559] CoreMusicLibrary::Adding element Serveurs Média Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:22:01 volumio2 volumio[1064]: info: UPNP Browser: Client initialized successfully Apr 14 14:22:01 volumio2 sudo[1424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:01 volumio2 sudo[1424]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 volumio[1064]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 14:22:01 volumio2 volumio[1064]: info: [1776169321574] CoreMusicLibrary::Adding element Last_100 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 14:22:01 volumio2 volumio[1064]: info: [1776169321574] CoreMusicLibrary::Adding element Webradio Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:22:01 volumio2 volumio[1064]: info: Initializing BBC Radios Apr 14 14:22:01 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 14:22:01 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 14:22:01 volumio2 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 14 14:22:01 volumio2 sudo[1421]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 systemd[1]: mpd.service: Deactivated successfully. Apr 14 14:22:01 volumio2 systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 14:22:01 volumio2 systemd[1]: mpd.socket: Deactivated successfully. Apr 14 14:22:01 volumio2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 14:22:01 volumio2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:22:01 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: Volumio Calling Home Apr 14 14:22:01 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 14:22:01 volumio2 sudo[1454]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 14:22:01 volumio2 sudo[1454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 14:22:01 volumio2 sudo[1458]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 14 14:22:01 volumio2 sudo[1454]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 volumio[1064]: Unhandled rejection Error: No sockets available, cannot start. Apr 14 14:22:01 volumio2 volumio[1064]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Apr 14 14:22:01 volumio2 volumio[1064]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Apr 14 14:22:01 volumio2 volumio[1064]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Apr 14 14:22:01 volumio2 volumio[1064]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Apr 14 14:22:01 volumio2 volumio[1064]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Apr 14 14:22:01 volumio2 volumio[1064]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Apr 14 14:22:01 volumio2 volumio[1064]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Apr 14 14:22:01 volumio2 volumio[1064]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Apr 14 14:22:01 volumio2 volumio[1064]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:156:14) Apr 14 14:22:01 volumio2 volumio[1064]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Apr 14 14:22:01 volumio2 volumio[1064]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Apr 14 14:22:01 volumio2 volumio[1064]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 14 14:22:01 volumio2 volumio[1064]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Apr 14 14:22:01 volumio2 volumio[1064]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Apr 14 14:22:01 volumio2 volumio[1064]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Apr 14 14:22:01 volumio2 volumio[1064]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 14 14:22:01 volumio2 volumio[1064]: info: MPD Permissions set Apr 14 14:22:01 volumio2 volumio[1064]: info: MPD Permissions set Apr 14 14:22:01 volumio2 volumio[1064]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:01 volumio2 volumio[1064]: info: Starting Shairport Sync Apr 14 14:22:01 volumio2 volumio[1064]: info: Starting Shairport Sync Apr 14 14:22:01 volumio2 volumio[1064]: info: Starting Shairport Sync Apr 14 14:22:01 volumio2 sudo[1488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 14:22:01 volumio2 sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 14:22:01 volumio2 sudo[1488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 sudo[1490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 14:22:01 volumio2 sudo[1490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:01 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:01 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 14:22:01 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 14:22:01 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 14:22:01 volumio2 systemd[1]: shairport-sync.service: Consumed 1.610s CPU time. Apr 14 14:22:01 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 14:22:01 volumio2 sudo[1490]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 sudo[1487]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 sudo[1488]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:01 volumio2 volumio[1064]: info: Shairport-Sync Started Apr 14 14:22:01 volumio2 volumio[1064]: Error adding Membership: Error: addMembership EINVAL Apr 14 14:22:01 volumio2 volumio[1064]: info: Shairport-Sync Started Apr 14 14:22:01 volumio2 volumio[1064]: info: Shairport-Sync Started Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.826+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Apr 14 14:22:01 volumio2 volumio[1064]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 14:22:01 volumio2 volumio[1064]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 14:22:01 volumio2 dbus-daemon[757]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.14' (uid=0 pid=1447 comm="/usr/bin/volumio5-onboarding") Apr 14 14:22:01 volumio2 systemd[1]: Starting bluetooth.service - Bluetooth service... Apr 14 14:22:01 volumio2 dhcpcd[809]: eth0: carrier acquired Apr 14 14:22:01 volumio2 kernel: r8169 0000:01:00.0 eth0: Link is Up - 1Gbps/Full - flow control rx/tx Apr 14 14:22:01 volumio2 dhcpcd[809]: eth0: IAID 59:d0:47:1c Apr 14 14:22:01 volumio2 bluetoothd[1522]: Bluetooth daemon 5.83 Apr 14 14:22:01 volumio2 kernel: Bluetooth: Core ver 2.22 Apr 14 14:22:01 volumio2 kernel: NET: Registered PF_BLUETOOTH protocol family Apr 14 14:22:01 volumio2 kernel: Bluetooth: HCI device and connection manager initialized Apr 14 14:22:01 volumio2 kernel: Bluetooth: HCI socket layer initialized Apr 14 14:22:01 volumio2 kernel: Bluetooth: L2CAP socket layer initialized Apr 14 14:22:01 volumio2 kernel: Bluetooth: SCO socket layer initialized Apr 14 14:22:01 volumio2 dbus-daemon[757]: [system] Successfully activated service 'org.bluez' Apr 14 14:22:01 volumio2 systemd[1]: Started bluetooth.service - Bluetooth service. Apr 14 14:22:01 volumio2 bluetoothd[1522]: Starting SDP server Apr 14 14:22:01 volumio2 bluetoothd[1522]: Excluding (cli) sap Apr 14 14:22:01 volumio2 bluetoothd[1522]: Excluding (cli) scanparam Apr 14 14:22:01 volumio2 bluetoothd[1522]: Excluding (cli) midi Apr 14 14:22:01 volumio2 bluetoothd[1522]: Excluding (cli) battery Apr 14 14:22:01 volumio2 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 14 14:22:01 volumio2 kernel: Bluetooth: BNEP filters: protocol multicast Apr 14 14:22:01 volumio2 kernel: Bluetooth: BNEP socket layer initialized Apr 14 14:22:01 volumio2 dbus-daemon[757]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.15' (uid=0 pid=1522 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 14 14:22:01 volumio2 bluetoothd[1522]: Bluetooth management interface 1.23 initialized Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.980+02:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist" Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.980+02:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist" Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.980+02:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist" Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.981+02:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist" Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.981+02:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist" Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.981+02:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled" Apr 14 14:22:01 volumio2 volumio[1064]: info: Received Get System Info Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:22:01 volumio2 volumio[1064]: info: Discovery: Getting this device information Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:01 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.984+02:00 level=INFO msg="system info for 2c7fcfe8660bd0ef1675699919a00b82" deviceName=Volumio2 deviceVariant=volumio deviceModel= softwareVersion=4.119 Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.986+02:00 level=INFO msg="bootstrapping state" hasInternet=false Apr 14 14:22:01 volumio2 volumio[1064]: info: Received Get System Info Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:22:01 volumio2 volumio[1064]: info: Discovery: Getting this device information Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:01 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 14:22:01 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 14:22:01 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:01.988+02:00 level=INFO msg="enabling local network discovery" Apr 14 14:22:02 volumio2 systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Apr 14 14:22:02 volumio2 dbus-daemon[757]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 14 14:22:02 volumio2 systemd[1]: Started systemd-hostnamed.service - Hostname Service. Apr 14 14:22:02 volumio2 volumio[1064]: info: Discovery: adding 204c304d-dfb2-4a93-b173-a57c77e5912e Apr 14 14:22:02 volumio2 volumio[1064]: info: Discovery: Found device Volumio2 Apr 14 14:22:02 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:02 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:02 volumio2 ntpd[999]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:02 volumio2 ntpd[999]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Apr 14 14:22:02 volumio2 ntpd[999]: DNS: dns_check: DNS error: -11, System error Apr 14 14:22:02 volumio2 ntpd[999]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Apr 14 14:22:02 volumio2 ifplugd(eth0)[997]: Link beat detected. Apr 14 14:22:02 volumio2 ifplugd(eth0)[997]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 14 14:22:02 volumio2 ifplugd(eth0)[997]: client: ifup: interface eth0 already configured Apr 14 14:22:02 volumio2 volumio[1064]: info: Received Get System Info Apr 14 14:22:02 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:22:02 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:22:02 volumio2 volumio[1064]: info: Discovery: Getting this device information Apr 14 14:22:02 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:02 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:02 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:22:02 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 14:22:02 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 14:22:02 volumio2 ifplugd(eth0)[997]: Program executed successfully. Apr 14 14:22:02 volumio2 mpd[1459]: 2026-04-14T14:22:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 14:22:02 volumio2 systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 14:22:02 volumio2 sudo[1426]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:02 volumio2 sudo[1413]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:02 volumio2 volumio[1064]: info: Completed starting Core Plugins Apr 14 14:22:02 volumio2 volumio[1064]: info: ------------------------------------------- Apr 14 14:22:02 volumio2 volumio[1064]: info: ----- MyVolumio plugins startup ---- Apr 14 14:22:02 volumio2 volumio[1064]: info: ------------------------------------------- Apr 14 14:22:02 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 14:22:02 volumio2 volumio[1064]: error: MPD error: The expression evaluated to a falsy value: Apr 14 14:22:02 volumio2 volumio[1064]: assert.ok(self.idling) Apr 14 14:22:02 volumio2 volumio[1064]: error: The expression evaluated to a falsy value: Apr 14 14:22:02 volumio2 volumio[1064]: assert.ok(self.idling) Apr 14 14:22:02 volumio2 volumio[1064]: error: updateQueue error: null Apr 14 14:22:02 volumio2 volumio[1064]: info: MPD running with PID1459 Apr 14 14:22:02 volumio2 volumio[1064]: ,establishing connection Apr 14 14:22:02 volumio2 volumio[1064]: error: updateQueue error: null Apr 14 14:22:02 volumio2 dhcpcd[809]: eth0: soliciting an IPv6 router Apr 14 14:22:02 volumio2 dhcpcd[809]: eth0: soliciting a DHCP lease Apr 14 14:22:02 volumio2 dhcpcd[809]: eth0: offered 192.168.1.166 from 192.168.1.254 Apr 14 14:22:03 volumio2 ntpd[999]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:03 volumio2 ntpd[999]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Apr 14 14:22:03 volumio2 ntpd[999]: DNS: dns_check: DNS error: -11, System error Apr 14 14:22:03 volumio2 ntpd[999]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Apr 14 14:22:03 volumio2 volumio[1064]: 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/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 14 14:22:03 volumio2 volumio[1064]: 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/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:03 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:22:03 volumio2 volumio[1064]: info: Listing playlists Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 14:22:03 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 14:22:03 volumio2 volumio-remote-updater[767]: [2026-04-14 14:22:03] [connect] Successful connection Apr 14 14:22:03 volumio2 volumio-remote-updater[767]: [2026-04-14 14:22:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776169323 101 Apr 14 14:22:03 volumio2 volumio[1064]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Apr 14 14:22:03 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:03.848+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 14 14:22:04 volumio2 bash[969]: setdatetime-helper: all HTTPS Date fallbacks failed Apr 14 14:22:04 volumio2 systemd[1]: setdatetime-helper.service: Deactivated successfully. Apr 14 14:22:04 volumio2 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Apr 14 14:22:05 volumio2 dhcpcd[809]: eth0: probing address 192.168.1.166/24 Apr 14 14:22:05 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 14:22:05 volumio2 volumio[1064]: info: Received Get System Info Apr 14 14:22:05 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:22:05 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:22:05 volumio2 volumio[1064]: info: Discovery: Getting this device information Apr 14 14:22:05 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:05 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:05 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:22:06 volumio2 kernel: logitech-hidpp-device 0003:046D:4054.0004: HID++ 4.5 device connected. Apr 14 14:22:07 volumio2 volumio[1064]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 14 14:22:09 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 14:22:09 volumio2 volumio[1064]: info: CURURI: albums:// Apr 14 14:22:09 volumio2 volumio[1064]: info: listAlbums - loading Albums from cache Apr 14 14:22:09 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetQueue Apr 14 14:22:09 volumio2 volumio[1064]: info: CoreStateMachine::getQueue Apr 14 14:22:09 volumio2 volumio[1064]: info: CorePlayQueue::getQueue Apr 14 14:22:09 volumio2 dhcpcd[809]: eth0: leased 192.168.1.166 for 43200 seconds Apr 14 14:22:09 volumio2 avahi-daemon[755]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.166. Apr 14 14:22:09 volumio2 avahi-daemon[755]: New relevant interface eth0.IPv4 for mDNS. Apr 14 14:22:09 volumio2 avahi-daemon[755]: Registering new address record for 192.168.1.166 on eth0.IPv4. Apr 14 14:22:09 volumio2 dhcpcd[809]: eth0: adding route to 192.168.1.0/24 Apr 14 14:22:09 volumio2 systemd[1]: welcome.service: Deactivated successfully. Apr 14 14:22:09 volumio2 systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 14 14:22:09 volumio2 systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 14 14:22:09 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:22:09 volumio2 dhcpcd[809]: eth0: adding default route via 192.168.1.254 Apr 14 14:22:09 volumio2 systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 14 14:22:09 volumio2 welcome[1734]: Resolved ip:[1] 192.168.1.166 Apr 14 14:22:09 volumio2 systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 14 14:22:09 volumio2 systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Apr 14 14:22:09 volumio2 systemd[1]: Started nmbd.service - Samba NMB Daemon. Apr 14 14:22:09 volumio2 systemd[1]: Starting winbind.service - Samba Winbind Daemon... Apr 14 14:22:09 volumio2 winbindd[1752]: [2026/04/14 14:22:09.763953, 0] ../../source3/winbindd/winbindd.c:1440(main) Apr 14 14:22:09 volumio2 winbindd[1752]: winbindd version 4.17.12-Debian started. Apr 14 14:22:09 volumio2 winbindd[1752]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Apr 14 14:22:09 volumio2 winbindd[1752]: [2026/04/14 14:22:09.766553, 0] ../../source3/winbindd/winbindd_cache.c:3117(initialize_winbindd_cache) Apr 14 14:22:09 volumio2 winbindd[1752]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 14 14:22:09 volumio2 systemd[1]: Started winbind.service - Samba Winbind Daemon. Apr 14 14:22:09 volumio2 systemd[1]: Starting smbd.service - Samba SMB Daemon... Apr 14 14:22:09 volumio2 smbd[1769]: [2026/04/14 14:22:09.875510, 0] ../../source3/smbd/server.c:1741(main) Apr 14 14:22:09 volumio2 smbd[1769]: smbd version 4.17.12-Debian started. Apr 14 14:22:09 volumio2 smbd[1769]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Apr 14 14:22:09 volumio2 systemd[1]: Started smbd.service - Samba SMB Daemon. Apr 14 14:22:09 volumio2 systemd[1]: Reached target multi-user.target - Multi-User System. Apr 14 14:22:09 volumio2 systemd[1]: Reached target graphical.target - Graphical Interface. Apr 14 14:22:09 volumio2 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Apr 14 14:22:09 volumio2 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Apr 14 14:22:09 volumio2 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Apr 14 14:22:09 volumio2 systemd[1]: Startup finished in 3.707s (firmware) + 635ms (loader) + 13.925s (kernel) + 12.780s (userspace) = 31.049s. Apr 14 14:22:10 volumio2 volumio[1064]: info: Received Get System Info Apr 14 14:22:10 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:22:10 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:22:10 volumio2 volumio[1064]: info: Discovery: Getting this device information Apr 14 14:22:10 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:10 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:10 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:22:10 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 14:22:10 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 14:22:10 volumio2 volumio[1064]: info: Discovery: this is already registered, 204c304d-dfb2-4a93-b173-a57c77e5912e Apr 14 14:22:10 volumio2 volumio[1064]: info: Discovery: Found device Volumio2 Apr 14 14:22:10 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:10 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:10 volumio2 volumio[1064]: info: Volumio Network Manager: Network status updated: 1 Apr 14 14:22:10 volumio2 sudo[1804]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 14:22:10 volumio2 sudo[1804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:10 volumio2 sudo[1804]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:10 volumio2 sudo[1806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 14:22:10 volumio2 sudo[1806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:10 volumio2 sudo[1811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 14:22:10 volumio2 sudo[1811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:10 volumio2 sudo[1806]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 14:22:10 volumio2 volumio[1064]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 14:22:10 volumio2 volumio[1064]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 14:22:10 volumio2 volumio[1064]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 14:22:10 volumio2 volumio[1064]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 14:22:10 volumio2 volumio[1064]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 14:22:10 volumio2 volumio[1064]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 14:22:10 volumio2 volumio[1064]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 14:22:10 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 14:22:11 volumio2 volumio[1064]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 14:22:11 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 14:22:11 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:11 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:11 volumio2 volumio[1064]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 14:22:11 volumio2 volumio[1064]: info: MyVolumio login type: Token Apr 14 14:22:11 volumio2 volumio5-onboarding[1447]: time=2026-04-14T14:22:11.040+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 14 14:22:11 volumio2 volumio[1064]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 14:22:11 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 14:22:11 volumio2 ntpd[999]: IO: Listen normally on 3 eth0 192.168.1.166:123 Apr 14 14:22:11 volumio2 ntpd[999]: IO: new interface(s) found: waking up resolver Apr 14 14:22:11 volumio2 ntpd[999]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:11 volumio2 ntpd[999]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Apr 14 14:22:11 volumio2 ntpd[999]: DNS: Pool taking: 79.143.250.33 Apr 14 14:22:11 volumio2 ntpd[999]: DNS: Pool taking: 162.159.200.123 Apr 14 14:22:11 volumio2 ntpd[999]: DNS: Pool taking: 82.64.81.218 Apr 14 14:22:11 volumio2 ntpd[999]: DNS: Pool taking: 162.159.200.1 Apr 14 14:22:11 volumio2 ntpd[999]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Apr 14 14:22:11 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 14:22:11 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 14:22:11 volumio2 volumio[1064]: info: Streaming services startup Apr 14 14:22:11 volumio2 volumio[1064]: info: Starting Streaming Daemon Apr 14 14:22:11 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 14:22:11 volumio2 sudo[1818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 14:22:11 volumio2 sudo[1818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:11 volumio2 sudo[1818]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:11 volumio2 volumio[1064]: error: Cannot start Volumio Streaming Daemon Apr 14 14:22:11 volumio2 volumio[1064]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 14:22:11 volumio2 volumio[1064]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 14:22:11 volumio2 volumio[1064]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 14:22:11 volumio2 volumio[1064]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.119&uuid=2c7fcfe8660bd0ef1675699919a00b82" http://updates.volumio.org/downloader-v1/track-device Apr 14 14:22:11 volumio2 volumio[1064]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 14 14:22:11 volumio2 volumio[1064]: Dload Upload Total Spent Left Speed Apr 14 14:22:11 volumio2 volumio[1064]: [132B blob data] Apr 14 14:22:11 volumio2 volumio[1064]: retrying in 5 seconds, trial 0 Apr 14 14:22:11 volumio2 volumio[1064]: info: Volumio Calling Home Apr 14 14:22:11 volumio2 volumio[1064]: info: Volumio called home Apr 14 14:22:11 volumio2 volumio[1064]: info: MyVolumio token set successfully Apr 14 14:22:11 volumio2 volumio[1064]: info: MYVOLUMIO: Adding device Apr 14 14:22:11 volumio2 volumio[1064]: info: MYVOLUMIO: Evaluating Server Apr 14 14:22:11 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 14:22:11 volumio2 volumio[1064]: info: CURURI: albums://Sarah%20Brightman/Timeless Apr 14 14:22:12 volumio2 volumio[1064]: info: MyVolumio Plan changed: premium Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 14 14:22:12 volumio2 volumio[1064]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 14:22:12 volumio2 volumio[1064]: info: Removing audio output: Apr 14 14:22:12 volumio2 volumio[1064]: info: MYVOLUMIO: Adding device Apr 14 14:22:12 volumio2 volumio[1064]: info: MYVOLUMIO: Evaluating Server Apr 14 14:22:12 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/01.No_One_Like_You.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/02.Just_Show_Me_How_to_Love_You.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/03.Tú_quieres_volver.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/04.In_pace.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/05.There_for_Me.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/06.Bilitis_-_Gènèrique.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/07.Who_Wants_to_Live_Forever.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/08.La_Wally.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/09.Naturaleza_muerta.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/10.En_Aranjuez_con_tu_amor.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/11.In_trutina.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/12.Time_to_Say_Goodbye_(Con_te_partirò).flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/13.O_mio_babbino_caro.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Preloading song: music-library/INTERNAL/Sarah_Brightman-Timeless/14.Alleluja.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Remote config written successfully Apr 14 14:22:12 volumio2 volumio[1064]: info: Starting Tunnel 1 Apr 14 14:22:12 volumio2 volumio[1064]: info: Starting Tunnel Connection Checker Apr 14 14:22:12 volumio2 volumio[1064]: info: Completed starting MyVolumio Plugin Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/01.No_One_Like_You.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F01.No_One_Like_You.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/01.No_One_Like_You.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/02.Just_Show_Me_How_to_Love_You.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F02.Just_Show_Me_How_to_Love_You.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/02.Just_Show_Me_How_to_Love_You.flac Apr 14 14:22:12 volumio2 ntpd[999]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 193.52.136.2 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 212.85.158.10 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 38.242.218.253 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 82.66.2.248 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 2001:41d0:801:2000::acb Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 2a01:7a7:2:3343:216:3cff:fe23:496 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 2a06:a880:5:d3cc::123 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: Pool taking: 2a01:cb00:129e:a803::278 Apr 14 14:22:12 volumio2 ntpd[999]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/03.Tú_quieres_volver.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: MYVolumio Device enabled Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 14 14:22:12 volumio2 volumio[1064]: info: MyVolumio status changed Apr 14 14:22:12 volumio2 volumio[1064]: info: Streaming services startup Apr 14 14:22:12 volumio2 volumio[1064]: info: Starting Streaming Daemon Apr 14 14:22:12 volumio2 sudo[1868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 14:22:12 volumio2 sudo[1868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F03.T%C3%BA_quieres_volver.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/03.Tú_quieres_volver.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 14 14:22:12 volumio2 sudo[1868]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 14 14:22:12 volumio2 volumio[1064]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Apr 14 14:22:12 volumio2 sudo[1874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 14 14:22:12 volumio2 sudo[1874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 sudo[1874]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: MultiRoom plugin initialized Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: STOPPING SNAPCLIENT Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: Snap server stop Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: STOPPING volumioStreaming Apr 14 14:22:12 volumio2 sudo[1891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 14 14:22:12 volumio2 sudo[1891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 sudo[1894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 14 14:22:12 volumio2 sudo[1894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 sudo[1895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 14 14:22:12 volumio2 sudo[1895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 sudo[1899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 14 14:22:12 volumio2 sudo[1899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 14 14:22:12 volumio2 sudo[1891]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 sudo[1899]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 14 14:22:12 volumio2 sudo[1894]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 sudo[1895]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Apr 14 14:22:12 volumio2 volumio[1064]: info: Preparing to generate the ALSA configuration file Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/04.In_pace.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/05.There_for_Me.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/06.Bilitis_-_Gènèrique.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/07.Who_Wants_to_Live_Forever.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/08.La_Wally.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/09.Naturaleza_muerta.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/10.En_Aranjuez_con_tu_amor.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 14 14:22:12 volumio2 volumio[1064]: info: Reading ALSA contributions from plugins. Apr 14 14:22:12 volumio2 volumio[1064]: info: Setting Geolocation for MyVolumio to eu4 Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: Setting Geolocation for MyVolumio to eu10 Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F04.In_pace.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/04.In_pace.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F05.There_for_Me.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/05.There_for_Me.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F06.Bilitis_-_G%C3%A8n%C3%A8rique.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/06.Bilitis_-_Gènèrique.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F07.Who_Wants_to_Live_Forever.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/07.Who_Wants_to_Live_Forever.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F08.La_Wally.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/08.La_Wally.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F09.Naturaleza_muerta.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/09.Naturaleza_muerta.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F10.En_Aranjuez_con_tu_amor.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/10.En_Aranjuez_con_tu_amor.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: Removed streaming files Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: volumioStreaming STOPPED Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: SNAPSERVER STOPPED Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: SNAPCLIENT STOPPED Apr 14 14:22:12 volumio2 volumio[1064]: error: Cannot start Volumio Streaming Daemon Apr 14 14:22:12 volumio2 volumio[1064]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 14:22:12 volumio2 volumio[1064]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 14:22:12 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/11.In_trutina.flac in service mpd Apr 14 14:22:12 volumio2 volumio[1064]: info: ALBUMART /albumart?cacheid=552&web=Sarah%20Brightman/Timeless/extralarge&path=%2Fmnt%2FINTERNAL%2FSarah_Brightman-Timeless%2F11.In_trutina.flac&metadata=false Apr 14 14:22:12 volumio2 volumio[1064]: info: URI /mnt/INTERNAL/Sarah_Brightman-Timeless/11.In_trutina.flac Apr 14 14:22:12 volumio2 volumio[1064]: info: Asound.conf file written Apr 14 14:22:12 volumio2 sudo[1905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 14 14:22:12 volumio2 sudo[1905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 sudo[1905]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 volumio[1064]: info: Output device has changed, restarting MPD Apr 14 14:22:12 volumio2 volumio[1064]: info: Output device has changed, restarting Shairport Sync Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:12 volumio2 sudo[1911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 14:22:12 volumio2 volumio[1064]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 14 14:22:12 volumio2 sudo[1913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 14:22:12 volumio2 sudo[1913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:12 volumio2 sudo[1911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:12 volumio2 sudo[1911]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output for this device Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output Apr 14 14:22:12 volumio2 systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding audio output: Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding audio output: Apr 14 14:22:12 volumio2 volumio[1064]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding METAVOLUMIO REST API Endpoints Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 14 14:22:12 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 14 14:22:12 volumio2 volumio[1064]: info: Preparing CD Folders Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding CD REST API Endpoints Apr 14 14:22:12 volumio2 volumio[1064]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 14 14:22:12 volumio2 volumio[1064]: info: Starting UDEV Watcher for CD Apr 14 14:22:12 volumio2 volumio[1064]: info: Detecting CD presence with UDEV Apr 14 14:22:12 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 14 14:22:12 volumio2 systemd[1]: mpd.service: Deactivated successfully. Apr 14 14:22:12 volumio2 systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 14:22:12 volumio2 systemd[1]: mpd.socket: Deactivated successfully. Apr 14 14:22:12 volumio2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 14:22:12 volumio2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 14:22:12 volumio2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 14:22:12 volumio2 systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 14:22:12 volumio2 sudo[1929]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 14:22:12 volumio2 sudo[1929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 14:22:12 volumio2 sudo[1929]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:12 volumio2 mpd[1931]: 2026-04-14T14:22:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 14:22:12 volumio2 systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 14:22:12 volumio2 sudo[1913]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:13 volumio2 ntpd[999]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:13 volumio2 ntpd[999]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Apr 14 14:22:13 volumio2 ntpd[999]: DNS: Pool taking: 31.58.102.164 Apr 14 14:22:13 volumio2 ntpd[999]: DNS: Pool taking: 193.42.63.23 Apr 14 14:22:13 volumio2 ntpd[999]: DNS: Pool taking: 82.64.141.144 Apr 14 14:22:13 volumio2 ntpd[999]: DNS: Pool taking: 37.59.63.125 Apr 14 14:22:13 volumio2 ntpd[999]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Apr 14 14:22:14 volumio2 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Apr 14 14:22:14 volumio2 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 14:22:14 volumio2 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 14:22:14 volumio2 sudo[1811]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:14 volumio2 ntpd[999]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 14:22:14 volumio2 ntpd[999]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Apr 14 14:22:14 volumio2 ntpd[999]: DNS: Pool taking: 109.190.177.205 Apr 14 14:22:14 volumio2 ntpd[999]: DNS: Pool skipping: 37.59.63.125 Apr 14 14:22:14 volumio2 ntpd[999]: DNS: Pool taking: 45.90.162.253 Apr 14 14:22:14 volumio2 ntpd[999]: DNS: Pool taking: 82.66.53.60 Apr 14 14:22:14 volumio2 ntpd[999]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Apr 14 14:22:18 volumio2 volumio[1064]: warn: [cd-plugin] cdspeedctl: speed unsupported by drive Apr 14 14:22:18 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding inputs REST Endpoints Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 14 14:22:18 volumio2 volumio[1064]: info: Scanning Audio Inputs Apr 14 14:22:18 volumio2 volumio[1064]: info: Checking against Known Cards name Apr 14 14:22:18 volumio2 volumio[1064]: info: Checking against Known Cards name Apr 14 14:22:18 volumio2 volumio[1064]: info: Checking against Known Cards name Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding Server instance for streaming Apr 14 14:22:18 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 14 14:22:18 volumio2 volumio[1064]: error: Hi Res Audio Failed Login: Missing Login Data Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 14 14:22:18 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 14 14:22:18 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 14 14:22:18 volumio2 volumio[1064]: info: Refreshing QOBUZ token Apr 14 14:22:18 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 14 14:22:18 volumio2 volumio[1064]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Apr 14 14:22:18 volumio2 sudo[1956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 14 14:22:18 volumio2 sudo[1956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: QobuzConnect: Starting Qobuz Connect socket and service Apr 14 14:22:18 volumio2 sudo[1956]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:18 volumio2 volumio[1064]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding TIDAL REST API Endpoints Apr 14 14:22:18 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/12.Time_to_Say_Goodbye_(Con_te_partirò).flac in service mpd Apr 14 14:22:18 volumio2 volumio[1064]: error: MPD error: Error: write EPIPE Apr 14 14:22:18 volumio2 volumio[1064]: error: write EPIPE {"code":"EPIPE","errno":-32,"syscall":"write"} Apr 14 14:22:18 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/13.O_mio_babbino_caro.flac in service mpd Apr 14 14:22:18 volumio2 volumio[1064]: info: Exploding uri music-library/INTERNAL/Sarah_Brightman-Timeless/14.Alleluja.flac in service mpd Apr 14 14:22:18 volumio2 volumio[1064]: info: Updating MyVolumio device info Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: Updating MyVolumio device info Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: MRS: Getting audio outputs on start Apr 14 14:22:18 volumio2 volumio[1064]: info: MRS: Requesting all other devices output Apr 14 14:22:18 volumio2 sudo[1963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 14 14:22:18 volumio2 sudo[1963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:18 volumio2 volumio[1064]: info: Successfully Added MyVolumio device Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 14:22:18 volumio2 volumio[1064]: info: Received Get System Info Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:22:18 volumio2 volumio[1064]: info: Discovery: Getting this device information Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:18 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:22:18 volumio2 volumio[1064]: info: Successfully Added MyVolumio device Apr 14 14:22:18 volumio2 volumio[1064]: info: MPD Permissions set Apr 14 14:22:18 volumio2 volumio[1064]: info: Upmpdcli Daemon Started Apr 14 14:22:18 volumio2 sudo[1963]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:18 volumio2 volumio[1064]: error: updateQueue error: null Apr 14 14:22:18 volumio2 sudo[1966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 14 14:22:18 volumio2 sudo[1966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:18 volumio2 volumio[1064]: info: Starting Shairport Sync Apr 14 14:22:18 volumio2 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 14 14:22:18 volumio2 sudo[1966]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:18 volumio2 sudo[1985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 14 14:22:18 volumio2 sudo[1985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:18 volumio2 sudo[1989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 14:22:18 volumio2 sudo[1989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:18 volumio2 volumio[1064]: info: MRS: Found cast device: Freebox-Player-POP-05dad96026a6ec6c675236c652e46f09 Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding audio output: Apr 14 14:22:18 volumio2 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 14:22:18 volumio2 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 14:22:18 volumio2 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 14 14:22:18 volumio2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 14:22:18 volumio2 sudo[1985]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:18 volumio2 systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 14:22:18 volumio2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 14:22:18 volumio2 systemd[1]: shairport-sync.service: Consumed 1.544s CPU time. Apr 14 14:22:18 volumio2 volumio[1064]: info: Remote SSH Started Apr 14 14:22:18 volumio2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 14:22:18 volumio2 sudo[1989]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:18 volumio2 autossh[1997]: port set to 0, monitoring disabled Apr 14 14:22:18 volumio2 autossh[1997]: starting ssh (count 1) Apr 14 14:22:18 volumio2 autossh[1997]: ssh child pid is 2014 Apr 14 14:22:18 volumio2 volumio[1064]: info: Shairport-Sync Started Apr 14 14:22:18 volumio2 volumio[1064]: info: Executing endpoint qc_getconfig Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.415 [1975.1975] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 14 14:22:18 volumio2 volumio[1064]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 14 14:22:18 volumio2 volumio[1064]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 14 14:22:18 volumio2 volumio[1064]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:18 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.434 [1975.1975] INFO VolumeManager: [0x561c5b1ead10]: Setting new playback volume: 75 Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.434 [1975.1975] INFO VolumeManager: [0x561c5b1ead10]: Setting new mute state: 0 Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.434 [1975.1975] INFO AudioStreamManager: [0x561c5b1ea870]: Setting new audio download buffer size: 1048576 Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.434 [1975.1975] INFO QobuzConnect: [0x561c5b1ebd20]: Client initialized! Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.434 [1975.1975] INFO SampleApp: Starting Avahi advertising, name: Volumio2, service name: _qobuz-connect._tcp Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.436 [1975.1975] INFO LocalConfigManager: [0x561c5b1ea350]: Starting Local Configuration server Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.436 [1975.1975] INFO SampleApp: Starting Local configuration server Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.436 [1975.1975] INFO SampleApp: Connected to UNIX socket client 0x561c5b1c0bb0 Apr 14 14:22:18 volumio2 volumiossh-tunnel[2014]: Warning: Permanently added '[eu10.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 14 14:22:18 volumio2 qobuz-connect[1975]: 20260414 14:22:18.566 [1975.1975] INFO SampleApp: Playback volume changed: 75 Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:18 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:18 volumio2 volumio[1064]: info: Access Token successfully retrieved Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 14:22:18 volumio2 volumio[1064]: info: [1776169338590] CoreMusicLibrary::Adding element QOBUZ Apr 14 14:22:18 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:22:18 volumio2 volumio[1064]: Cannot find translation for source QOBUZ Apr 14 14:22:18 volumio2 volumio[1064]: info: Stopping AccessToken refresher cron for QOBUZ Apr 14 14:22:18 volumio2 volumio[1064]: info: AccessToken refresher cron started for QOBUZ Apr 14 14:22:18 volumio2 volumio[1064]: info: Adding QOBUZ REST API Endpoints Apr 14 14:22:18 volumio2 volumio[1064]: info: Successfully Updated MyVolumio device Apr 14 14:22:18 volumio2 volumio[1064]: info: Successfully Updated MyVolumio device Apr 14 14:22:19 volumio2 upmpdcli[2023]: writing RSA key Apr 14 14:22:20 volumio2 qobuz-connect[1975]: 20260414 14:22:20.566 [1975.2019] INFO SampleApp: API endpoint invoked: get-display-info Apr 14 14:22:21 volumio2 volumio[1064]: info: TidalConnect service stoped! Apr 14 14:22:21 volumio2 volumio[1064]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 14 14:22:21 volumio2 volumio[1064]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 14 14:22:21 volumio2 sudo[2051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 14 14:22:21 volumio2 sudo[2051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 14:22:21 volumio2 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 14 14:22:21 volumio2 sudo[2051]: pam_unix(sudo:session): session closed for user root Apr 14 14:22:21 volumio2 volumio[1064]: info: Executing endpoint tc_getconfig Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 14 14:22:21 volumio2 vtcs[2054]: STARTING TidalConnect services, version: 1.6.1 Apr 14 14:22:21 volumio2 vtcs[2054]: STARTED TidalConnect services. Apr 14 14:22:21 volumio2 volumio[1064]: info: Executing endpoint tc_connect Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 14 14:22:21 volumio2 volumio[1064]: info: Connecting to TidalConnect Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::servicePushState Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:22:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:22:21 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output update for this device Apr 14 14:22:21 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:21 volumio2 volumio[1064]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::servicePushState Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:22:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:22:21 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output update for this device Apr 14 14:22:21 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:21 volumio2 volumio[1064]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 14:22:21 volumio2 volumio[1064]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 14 14:22:21 volumio2 volumio[1064]: info: Received Get System Version Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:22:21 volumio2 volumio[1064]: info: Received Get System Info Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 14:22:21 volumio2 volumio[1064]: info: Discovery: Getting this device information Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 14:22:24 volumio2 volumio[1064]: info: TidalConnect service started! Apr 14 14:22:24 volumio2 volumio[1064]: [Metrics] CommandRouter: 24s 236.77ms Apr 14 14:22:24 volumio2 volumio[1064]: info: CoreCommandRouter::volumiosetStartupVolume Apr 14 14:22:24 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:24 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:24 volumio2 volumio[1064]: info: CoreCommandRouter::Close All Modals sent Apr 14 14:22:24 volumio2 volumio[1064]: info: CoreCommandRouter::Close All Modals sent Apr 14 14:22:25 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 14 14:22:25 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 14 14:22:25 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 14 14:22:26 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 14:22:26 volumio2 volumio[1064]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 14 14:22:26 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:22:26 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:22:27 volumio2 systemd[1]: systemd-fsckd.service: Deactivated successfully. Apr 14 14:22:30 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 14 14:22:30 volumio2 volumio[1064]: info: handleBrowseUri took 51 milliseconds Apr 14 14:22:30 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:22:30 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetBrowseSources Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:22:31 volumio2 volumio[1064]: info: BOOT COMPLETED Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 14:22:31 volumio2 volumio-remote-updater[767]: Test mode disabled Apr 14 14:22:31 volumio2 volumio-remote-updater[767]: Alpha mode disabled Apr 14 14:22:31 volumio2 volumio-remote-updater[767]: Alpha legacy test mode disabled Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 14 14:22:31 volumio2 volumio[1064]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 14 14:22:31 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 14 14:22:32 volumio2 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Apr 14 14:22:39 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 14 14:22:39 volumio2 volumio[1064]: info: handleBrowseUri took 201 milliseconds Apr 14 14:22:39 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:22:46 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 14 14:22:46 volumio2 volumio[1064]: info: handleBrowseUri took 451 milliseconds Apr 14 14:22:46 volumio2 volumio[1064]: info: Executing endpoint metavolumio Apr 14 14:22:46 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 14 14:22:46 volumio2 volumio[1064]: info: Executing endpoint metavolumio Apr 14 14:22:46 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 14 14:22:46 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:22:46 volumio2 volumio[1064]: info: Preloading song: qobuz://song/114826851 Apr 14 14:22:46 volumio2 volumio[1064]: info: Preloading song: qobuz://song/114826852 Apr 14 14:22:46 volumio2 volumio[1064]: info: Preloading song: qobuz://song/114826853 Apr 14 14:22:46 volumio2 volumio[1064]: info: Exploding uri qobuz://song/114826851 in service qobuz Apr 14 14:22:46 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:22:46 volumio2 volumio[1064]: info: Exploding uri qobuz://song/114826852 in service qobuz Apr 14 14:22:46 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:22:46 volumio2 volumio[1064]: info: Exploding uri qobuz://song/114826853 in service qobuz Apr 14 14:22:46 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:22:46 volumio2 volumio[1064]: info: explodeUri took 125 milliseconds Apr 14 14:22:47 volumio2 volumio[1064]: info: explodeUri took 209 milliseconds Apr 14 14:22:47 volumio2 volumio[1064]: info: explodeUri took 367 milliseconds Apr 14 14:22:53 volumio2 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Apr 14 14:22:53 volumio2 systemd[1]: setdatetime-helper.service: Deactivated successfully. Apr 14 14:22:53 volumio2 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Apr 14 14:23:06 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 14 14:23:06 volumio2 volumio[1064]: info: handleBrowseUri took 244 milliseconds Apr 14 14:23:06 volumio2 volumio[1064]: info: Executing endpoint metavolumio Apr 14 14:23:06 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 14 14:23:06 volumio2 volumio[1064]: info: Executing endpoint metavolumio Apr 14 14:23:06 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 14 14:23:06 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196380 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196381 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196382 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196383 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196384 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196385 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196386 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196387 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196388 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196389 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196390 Apr 14 14:23:06 volumio2 volumio[1064]: info: Preloading song: qobuz://song/36196391 Apr 14 14:23:06 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196380 in service qobuz Apr 14 14:23:06 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:06 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196381 in service qobuz Apr 14 14:23:06 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:06 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196382 in service qobuz Apr 14 14:23:06 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:06 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196383 in service qobuz Apr 14 14:23:06 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:06 volumio2 volumio[1064]: info: explodeUri took 165 milliseconds Apr 14 14:23:06 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196384 in service qobuz Apr 14 14:23:06 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:06 volumio2 volumio[1064]: info: explodeUri took 166 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196385 in service qobuz Apr 14 14:23:07 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 192 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196386 in service qobuz Apr 14 14:23:07 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 192 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196387 in service qobuz Apr 14 14:23:07 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:07 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196388 in service qobuz Apr 14 14:23:07 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:07 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196389 in service qobuz Apr 14 14:23:07 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 265 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196390 in service qobuz Apr 14 14:23:07 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 264 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: Exploding uri qobuz://song/36196391 in service qobuz Apr 14 14:23:07 volumio2 volumio[1064]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 252 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 201 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 230 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 194 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 155 milliseconds Apr 14 14:23:07 volumio2 volumio[1064]: info: explodeUri took 217 milliseconds Apr 14 14:23:08 volumio2 volumio[1064]: info: MRS: Found cast device: BRAVIA-4K-2015-baaaa6902650b029421a5be05ea6d6a5 Apr 14 14:23:08 volumio2 volumio[1064]: info: Adding audio output: Apr 14 14:23:16 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioAddQueueItems Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::addQueueItems Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::addQueueItems Apr 14 14:23:16 volumio2 volumio[1064]: info: Preload queue cleared Apr 14 14:23:16 volumio2 volumio[1064]: info: Adding Item to queue: qobuz://song/36196380 Apr 14 14:23:16 volumio2 volumio[1064]: info: Using cached record of: qobuz://song/36196380 Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushQueue Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::saveQueue Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::updateTrackBlock Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::getTrackBlock Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 0 Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPlay Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::play index 43 Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::stop Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::play index undefined Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 43 Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::startPlaybackTimer Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 43 Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 14 14:23:16 volumio2 volumio[1064]: info: [1776169396386] ControllerQobuz::clearAddPlayTrack Apr 14 14:23:16 volumio2 volumio[1064]: info: getStreamUrl took 229 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand stop took 1 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand clear Apr 14 14:23:16 volumio2 volumio[1064]: info: Apr 14 14:23:16 volumio2 volumio[1064]: ---------------------------- MPD announces system playlist update Apr 14 14:23:16 volumio2 volumio[1064]: info: Ignoring MPD Status Update Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand clear took 1 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8" Apr 14 14:23:16 volumio2 volumio[1064]: error: updateQueue error: null Apr 14 14:23:16 volumio2 volumio[1064]: info: ------------------------------ 158ms Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8" Apr 14 14:23:16 volumio2 volumio[1064]: info: Apr 14 14:23:16 volumio2 volumio[1064]: ---------------------------- MPD announces system playlist update Apr 14 14:23:16 volumio2 volumio[1064]: info: Ignoring MPD Status Update Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8" took 0 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand play Apr 14 14:23:16 volumio2 volumio[1064]: info: ------------------------------ 0ms Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand play took 0 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: info: Apr 14 14:23:16 volumio2 volumio[1064]: ---------------------------- MPD announces state update: player Apr 14 14:23:16 volumio2 volumio[1064]: info: ControllerMpd::getState Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand status Apr 14 14:23:16 volumio2 volumio[1064]: info: Apr 14 14:23:16 volumio2 volumio[1064]: ---------------------------- MPD announces state update: player Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand status took 72 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: info: ControllerMpd::getState Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand status Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::parseState Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand status took 1 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::parseState Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::parseTrackInfo Apr 14 14:23:16 volumio2 volumio[1064]: info: ControllerMpd::pushState Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::servicePushState Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 43 Apr 14 14:23:16 volumio2 volumio[1064]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":208,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1257 Kbps","isStreaming":false,"title":"file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8","trackType":"qobuz"} Apr 14 14:23:16 volumio2 volumio[1064]: verbose: CURRENT POSITION 43 Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::syncState stateService play Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::syncState currentStatus stop Apr 14 14:23:16 volumio2 volumio[1064]: info: ------------------------------ 74ms Apr 14 14:23:16 volumio2 volumio[1064]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 14:23:16 volumio2 volumio[1064]: verbose: ControllerMpd::parseTrackInfo Apr 14 14:23:16 volumio2 volumio[1064]: info: ControllerMpd::pushState Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::servicePushState Apr 14 14:23:16 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 43 Apr 14 14:23:16 volumio2 volumio[1064]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1241,"duration":208,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2261 Kbps","isStreaming":false,"title":"file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8","trackType":"qobuz"} Apr 14 14:23:16 volumio2 volumio[1064]: verbose: CURRENT POSITION 43 Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::syncState stateService play Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::syncState currentStatus play Apr 14 14:23:16 volumio2 volumio[1064]: info: Received an update from plugin. extracting info from payload Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:23:16 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output update for this device Apr 14 14:23:16 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:23:16 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output update for this device Apr 14 14:23:16 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output Apr 14 14:23:16 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:23:16 volumio2 volumio[1064]: info: ------------------------------ 7ms Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPause Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::pause Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::stPlaybackTimer Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::servicePause Apr 14 14:23:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 43 Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreCommandRouter::servicePause Apr 14 14:23:21 volumio2 volumio[1064]: info: [1776169401520] ControllerQobuz::pause Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 14 14:23:21 volumio2 volumio[1064]: info: ControllerMpd::pause Apr 14 14:23:21 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand pause Apr 14 14:23:21 volumio2 volumio[1064]: info: Apr 14 14:23:21 volumio2 volumio[1064]: ---------------------------- MPD announces state update: player Apr 14 14:23:21 volumio2 volumio[1064]: info: sendMpdCommand pause took 1 milliseconds Apr 14 14:23:21 volumio2 volumio[1064]: info: ControllerMpd::getState Apr 14 14:23:21 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand status Apr 14 14:23:21 volumio2 volumio[1064]: info: sendMpdCommand status took 0 milliseconds Apr 14 14:23:21 volumio2 volumio[1064]: verbose: ControllerMpd::parseState Apr 14 14:23:21 volumio2 volumio[1064]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 14:23:21 volumio2 volumio[1064]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 14 14:23:21 volumio2 volumio[1064]: verbose: ControllerMpd::parseTrackInfo Apr 14 14:23:21 volumio2 volumio[1064]: info: ControllerMpd::pushState Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreCommandRouter::servicePushState Apr 14 14:23:21 volumio2 volumio[1064]: info: CorePlayQueue::getTrack 43 Apr 14 14:23:21 volumio2 volumio[1064]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5994,"duration":208,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2731 Kbps","isStreaming":false,"title":"file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=10114449&eid=36196380&fmt=7&profile=raw&app_id=539451548&cid=3808648&etsp=1776172996&hmac=jMRRhSr3UNqFQZKPeZW83kFp9j8","trackType":"qobuz"} Apr 14 14:23:21 volumio2 volumio[1064]: verbose: CURRENT POSITION 43 Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::syncState stateService pause Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::syncState currentStatus pause Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::pushState Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioPushState Apr 14 14:23:21 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output update for this device Apr 14 14:23:21 volumio2 volumio[1064]: info: MRS: Pushing multiroomSync output Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreCommandRouter::volumioGetState Apr 14 14:23:21 volumio2 volumio[1064]: info: CoreStateMachine::stPlaybackTimer Apr 14 14:23:21 volumio2 volumio[1064]: info: ------------------------------ 5ms Apr 14 14:23:29 volumio2 volumio[1064]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Apr 14 14:23:29 volumio2 volumio[1064]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Apr 14 14:23:29 volumio2 volumio[1064]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 14:23:29 volumio2 volumio[1064]: TypeError: Cannot read properties of undefined (reading 'then') Apr 14 14:23:29 volumio2 volumio[1064]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Apr 14 14:23:29 volumio2 volumio[1064]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) Apr 14 14:23:29 volumio2 volumio[1064]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1467:26) Apr 14 14:23:29 volumio2 volumio[1064]: at Socket.emit (node:events:514:28) Apr 14 14:23:29 volumio2 volumio[1064]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 14 14:23:29 volumio2 volumio[1064]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Apr 14 14:23:29 volumio2 volumio[1064]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 14:23:30 volumio2 sudo[2310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 14:22' Apr 14 14:23:30 volumio2 sudo[2310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"