Jun 20 17:56:13 volumio-vm startx[1936]: xinit: giving up Jun 20 17:56:13 volumio-vm startx[1936]: xinit: unable to connect to X server: Connection refused Jun 20 17:56:13 volumio-vm startx[1936]: xinit: server error Jun 20 17:56:13 volumio-vm systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Jun 20 17:56:13 volumio-vm systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Jun 20 17:56:13 volumio-vm sudo[1987]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/killall node Jun 20 17:56:13 volumio-vm sudo[1987]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Jun 20 17:56:13 volumio-vm sudo[1987]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:13 volumio-vm vtcs[1651]: [2025-06-20 17:56:13.952] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Jun 20 17:56:13 volumio-vm systemd[1]: volumio.service: Deactivated successfully. Jun 20 17:56:13 volumio-vm volumio-remote-updater[795]: [2025-06-20 17:56:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jun 20 17:56:13 volumio-vm volumio-remote-updater[795]: [2025-06-20 17:56:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jun 20 17:56:13 volumio-vm systemd[1]: volumio.service: Consumed 5.957s CPU time. Jun 20 17:56:13 volumio-vm systemd[1]: Started dynamicswap.service - dynamicswap service. Jun 20 17:56:13 volumio-vm systemd[1]: dynamicswap.service: Deactivated successfully. Jun 20 17:56:14 volumio-vm systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Jun 20 17:56:14 volumio-vm systemd[1]: Started dynamicswap.service - dynamicswap service. Jun 20 17:56:14 volumio-vm systemd[1]: Stopped volumio.service - Volumio Backend Module. Jun 20 17:56:14 volumio-vm systemd[1]: volumio.service: Consumed 5.957s CPU time. Jun 20 17:56:14 volumio-vm systemd[1]: Started volumio.service - Volumio Backend Module. Jun 20 17:56:14 volumio-vm systemd[1]: dynamicswap.service: Deactivated successfully. Jun 20 17:56:14 volumio-vm volumio[2000]: info: ------------------------------------------- Jun 20 17:56:14 volumio-vm volumio[2000]: info: ----- Volumio3 ---- Jun 20 17:56:14 volumio-vm volumio[2000]: info: ------------------------------------------- Jun 20 17:56:14 volumio-vm volumio[2000]: info: ----- System startup ---- Jun 20 17:56:14 volumio-vm volumio[2000]: info: ------------------------------------------- Jun 20 17:56:14 volumio-vm volumio[2000]: info: MYVOLUMIO Environment detected Jun 20 17:56:14 volumio-vm volumio[2000]: info: Plugin folders cleanup Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning into folder /volumio/app/plugins/ Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning category audio_interface Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning category miscellanea Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning category music_service Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning category plugins.json Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning category system_controller Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning category user_interface Jun 20 17:56:14 volumio-vm volumio[2000]: info: Scanning into folder /data/plugins/ Jun 20 17:56:14 volumio-vm volumio[2000]: info: Plugin folders cleanup completed Jun 20 17:56:14 volumio-vm volumio[2000]: info: ------------------------------------------- Jun 20 17:56:14 volumio-vm volumio[2000]: info: ----- Core plugins startup ---- Jun 20 17:56:14 volumio-vm volumio[2000]: info: ------------------------------------------- Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugins from folder /volumio/app/plugins/ Jun 20 17:56:14 volumio-vm volumio[2000]: info: Adding plugin upnp to MyMusic Plugins Jun 20 17:56:14 volumio-vm volumio[2000]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 20 17:56:14 volumio-vm volumio[2000]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugins from folder /data/plugins/ Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "system"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "appearance"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "network"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Refreshing Cached IP Addresses Jun 20 17:56:14 volumio-vm sudo[2028]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 20 17:56:14 volumio-vm sudo[2028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm sudo[2028]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm sudo[2038]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 20 17:56:14 volumio-vm sudo[2030]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 20 17:56:14 volumio-vm sudo[2030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm sudo[2038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "services"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "alsa_controller"... Jun 20 17:56:14 volumio-vm sudo[2038]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm sudo[2030]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "wizard"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "networkfs"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Starting Udev Watcher for removable devices Jun 20 17:56:14 volumio-vm volumio[2000]: info: Ignoring mount for partition: boot Jun 20 17:56:14 volumio-vm volumio[2000]: info: Ignoring mount for partition: volumio Jun 20 17:56:14 volumio-vm volumio[2000]: info: Ignoring mount for partition: volumio_data Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "volumio_command_line_client"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "upnp"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: [1750434974546] Starting Upmpd Daemon Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "my_music"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "mpd"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "upnp_browser"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "alarm-clock"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "airplay_emulation"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Starting Shairport Sync Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "last_100"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "webradio"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "i2s_dacs"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: I2S DAC not set, start Auto-detection Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "volumiodiscovery"... Jun 20 17:56:14 volumio-vm volumio[2000]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 20 17:56:14 volumio-vm volumio[2000]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 20 17:56:14 volumio-vm node[2000]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 20 17:56:14 volumio-vm volumio[2000]: *** WARNING *** For more information see Jun 20 17:56:14 volumio-vm volumio[2000]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 20 17:56:14 volumio-vm volumio[2000]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 20 17:56:14 volumio-vm volumio[2000]: *** WARNING *** For more information see Jun 20 17:56:14 volumio-vm node[2000]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 20 17:56:14 volumio-vm node[2000]: *** WARNING *** For more information see Jun 20 17:56:14 volumio-vm node[2000]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 20 17:56:14 volumio-vm node[2000]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 20 17:56:14 volumio-vm node[2000]: *** WARNING *** For more information see Jun 20 17:56:14 volumio-vm volumio[2000]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 20 17:56:14 volumio-vm volumio[2000]: info: Discovery: Started advertising with name: Volumio VM Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "outputs"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "albumart"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Plugin example_plugin is not enabled Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "inputs"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "updater_comm"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Plugin mpdemulation is not enabled Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "rest_api"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading plugin "websocket"... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Starting Socket.io Server version 1.7.4 Jun 20 17:56:14 volumio-vm volumio[2000]: info: Loading i18n strings for locale en Jun 20 17:56:14 volumio-vm volumio[2000]: Updating browse sources language Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 20 17:56:14 volumio-vm volumio[2068]: Forking 1 albumart workers Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::initPlayerControls Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: Express server listening on port 3000 Jun 20 17:56:14 volumio-vm volumio[2000]: [Metrics] WebUI: 0s 430.52ms Jun 20 17:56:14 volumio-vm volumio[2000]: info: Setting Device type: x86 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::resetVolumioState Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::getcurrentVolume Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioRetrievevolume Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jun 20 17:56:14 volumio-vm volumio[2000]: info: Completed loading Core Plugins Jun 20 17:56:14 volumio-vm volumio[2000]: info: Preparing to generate the ALSA configuration file Jun 20 17:56:14 volumio-vm volumio[2000]: info: Cannot read play queue from file Jun 20 17:56:14 volumio-vm volumio[2000]: info: Volumio Network Manager: Network status updated: 1 Jun 20 17:56:14 volumio-vm volumio[2000]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jun 20 17:56:14 volumio-vm volumio[2000]: wlan0 Interface doesn't support scanning. Jun 20 17:56:14 volumio-vm volumio[2000]: info: Cannot use regular scanning, forcing with ap-force Jun 20 17:56:14 volumio-vm sudo[2092]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jun 20 17:56:14 volumio-vm sudo[2092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm sudo[2092]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm volumio[2000]: command failed: No such device (-19) Jun 20 17:56:14 volumio-vm volumio[2000]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Jun 20 17:56:14 volumio-vm volumio[2000]: command failed: No such device (-19) Jun 20 17:56:14 volumio-vm volumio[2000]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jun 20 17:56:14 volumio-vm volumio[2000]: info: VolumeController:: Volume=47 Mute =false Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::updateTrackBlock Jun 20 17:56:14 volumio-vm volumio[2000]: info: CorePlayQueue::getTrackBlock Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioRetrievevolume Jun 20 17:56:14 volumio-vm volumio[2000]: info: VolumeController:: Volume=47 Mute =false Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: Asound.conf file unchanged, so no further update is needed Jun 20 17:56:14 volumio-vm volumio[2000]: info: Output device has changed, restarting MPD Jun 20 17:56:14 volumio-vm volumio[2000]: info: Output device has changed, restarting Shairport Sync Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:14 volumio-vm sudo[2106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 20 17:56:14 volumio-vm sudo[2106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm sudo[2106]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm sudo[2107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 20 17:56:14 volumio-vm sudo[2107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm volumio[2000]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 20 17:56:14 volumio-vm volumio[2000]: info: ___________ START PLUGINS ___________ Jun 20 17:56:14 volumio-vm volumio[2000]: info: ControllerMpd::onStart: Initializing MPD Jun 20 17:56:14 volumio-vm volumio[2000]: info: Creating MPD Configuration file Jun 20 17:56:14 volumio-vm systemd[1]: Stopping mpd.service - Music Player Daemon... Jun 20 17:56:14 volumio-vm sudo[2115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 20 17:56:14 volumio-vm sudo[2115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 20 17:56:14 volumio-vm volumio[2000]: info: [1750434974817] CoreMusicLibrary::Adding element Media Servers Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 20 17:56:14 volumio-vm sudo[2115]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm sudo[2118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 20 17:56:14 volumio-vm sudo[2118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm systemd[1]: mpd.service: Deactivated successfully. Jun 20 17:56:14 volumio-vm systemd[1]: Stopped mpd.service - Music Player Daemon. Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:14 volumio-vm systemd[1]: mpd.socket: Deactivated successfully. Jun 20 17:56:14 volumio-vm systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jun 20 17:56:14 volumio-vm systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jun 20 17:56:14 volumio-vm volumio[2000]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 20 17:56:14 volumio-vm volumio[2000]: info: [1750434974829] CoreMusicLibrary::Adding element Last_100 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 20 17:56:14 volumio-vm volumio[2000]: info: [1750434974829] CoreMusicLibrary::Adding element Webradio Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 20 17:56:14 volumio-vm volumio[2000]: info: Initializing BBC Radios Jun 20 17:56:14 volumio-vm systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jun 20 17:56:14 volumio-vm systemd[1]: Starting mpd.service - Music Player Daemon... Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: Volumio Calling Home Jun 20 17:56:14 volumio-vm systemd[1]: mpd.service: Deactivated successfully. Jun 20 17:56:14 volumio-vm systemd[1]: Stopped mpd.service - Music Player Daemon. Jun 20 17:56:14 volumio-vm systemd[1]: mpd.socket: Deactivated successfully. Jun 20 17:56:14 volumio-vm systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jun 20 17:56:14 volumio-vm systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jun 20 17:56:14 volumio-vm systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jun 20 17:56:14 volumio-vm systemd[1]: Starting mpd.service - Music Player Daemon... Jun 20 17:56:14 volumio-vm volumio[2078]: Starting albumart workers Jun 20 17:56:14 volumio-vm sudo[2147]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::setRepeat null single undefined Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::setRandom null Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:14 volumio-vm volumio[2000]: info: MPD Permissions set Jun 20 17:56:14 volumio-vm volumio[2000]: info: MPD Permissions set Jun 20 17:56:14 volumio-vm sudo[2147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 20 17:56:14 volumio-vm sudo[2147]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm volumio[2000]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 20 17:56:14 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:14 volumio-vm volumio[2000]: info: Starting Shairport Sync Jun 20 17:56:14 volumio-vm volumio[2000]: info: Starting Shairport Sync Jun 20 17:56:14 volumio-vm sudo[2169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 20 17:56:14 volumio-vm volumio[2000]: info: Starting Shairport Sync Jun 20 17:56:14 volumio-vm sudo[2167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 20 17:56:14 volumio-vm sudo[2167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm sudo[2169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jun 20 17:56:14 volumio-vm systemd[1]: shairport-sync.service: Deactivated successfully. Jun 20 17:56:14 volumio-vm systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 20 17:56:14 volumio-vm systemd[1]: shairport-sync.service: Consumed 2.018s CPU time. Jun 20 17:56:14 volumio-vm volumio[2000]: info: Volumio called home Jun 20 17:56:14 volumio-vm sudo[2173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 20 17:56:14 volumio-vm sudo[2173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:14 volumio-vm volumio[2000]: info: Discovery: A device disappeared from network Jun 20 17:56:14 volumio-vm volumio[2000]: info: Discovery: Browse raised the following error TypeError: Cannot read properties of undefined (reading 'toLowerCase') Jun 20 17:56:14 volumio-vm volumio[2000]: info: Discovery: A device disappeared from network Jun 20 17:56:14 volumio-vm volumio[2000]: info: Discovery: Browse raised the following error TypeError: Cannot read properties of undefined (reading 'toLowerCase') Jun 20 17:56:14 volumio-vm systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 20 17:56:14 volumio-vm sudo[2169]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm volumio[2000]: info: Shairport-Sync Started Jun 20 17:56:14 volumio-vm volumio[2000]: Error adding Membership: Error: addMembership EINVAL Jun 20 17:56:14 volumio-vm systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jun 20 17:56:14 volumio-vm systemd[1]: shairport-sync.service: Deactivated successfully. Jun 20 17:56:14 volumio-vm systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 20 17:56:14 volumio-vm systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 20 17:56:14 volumio-vm sudo[2173]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm sudo[2167]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:14 volumio-vm volumio[2000]: info: Shairport-Sync Started Jun 20 17:56:14 volumio-vm volumio[2000]: info: Shairport-Sync Started Jun 20 17:56:15 volumio-vm mpd[2149]: 2025-06-20T17:56:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 20 17:56:15 volumio-vm systemd[1]: Started mpd.service - Music Player Daemon. Jun 20 17:56:15 volumio-vm sudo[2118]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:15 volumio-vm volumio[2000]: info: Completed starting Core Plugins Jun 20 17:56:15 volumio-vm volumio[2000]: info: ------------------------------------------- Jun 20 17:56:15 volumio-vm volumio[2000]: info: ----- MyVolumio plugins startup ---- Jun 20 17:56:15 volumio-vm volumio[2000]: info: ------------------------------------------- Jun 20 17:56:15 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 20 17:56:15 volumio-vm volumio[2000]: error: updateQueue error: null Jun 20 17:56:15 volumio-vm sudo[2107]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:15 volumio-vm volumio[2000]: info: MPD running with PID2149 Jun 20 17:56:15 volumio-vm volumio[2000]: ,establishing connection Jun 20 17:56:15 volumio-vm volumio[2000]: error: MPD error: The expression evaluated to a falsy value: Jun 20 17:56:15 volumio-vm volumio[2000]: assert.ok(self.idling) Jun 20 17:56:15 volumio-vm volumio[2000]: error: The expression evaluated to a falsy value: Jun 20 17:56:15 volumio-vm volumio[2000]: assert.ok(self.idling) Jun 20 17:56:15 volumio-vm volumio[2000]: error: updateQueue error: null Jun 20 17:56:18 volumio-vm systemd[1]: volumio-kiosk.service: Scheduled restart job, restart counter is at 4. Jun 20 17:56:18 volumio-vm systemd[1]: Stopped volumio-kiosk.service - Start Volumio Kiosk. Jun 20 17:56:18 volumio-vm systemd[1]: Started volumio-kiosk.service - Start Volumio Kiosk. Jun 20 17:56:18 volumio-vm startx[2231]: X.Org X Server 1.21.1.7 Jun 20 17:56:18 volumio-vm startx[2231]: X Protocol Version 11, Revision 0 Jun 20 17:56:18 volumio-vm startx[2231]: Current Operating System: Linux volumio-vm 6.12.30-volumio #2 SMP PREEMPT_DYNAMIC Wed May 28 19:37:30 BST 2025 x86_64 Jun 20 17:56:18 volumio-vm startx[2231]: Kernel command line: BOOT_IMAGE=vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=fe897e9c-0d5f-4cba-bc7b-576cf9309cc2 bootpart=UUID=E667-2E51 datapart=UUID=9654a8ab-19c6-439c-9b73-299d49ed7131 hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=vendor net.ifnames=0 use_kmsg=no initrd=volumio.initrd Jun 20 17:56:18 volumio-vm startx[2231]: xorg-server 2:21.1.7-3+deb12u9 (https://www.debian.org/support) Jun 20 17:56:18 volumio-vm startx[2231]: Current version of pixman: 0.42.2 Jun 20 17:56:18 volumio-vm startx[2231]: Before reporting problems, check http://wiki.x.org Jun 20 17:56:18 volumio-vm startx[2231]: to make sure that you have the latest version. Jun 20 17:56:18 volumio-vm startx[2231]: Markers: (--) probed, (**) from config file, (==) default setting, Jun 20 17:56:18 volumio-vm startx[2231]: (++) from command line, (!!) notice, (II) informational, Jun 20 17:56:18 volumio-vm startx[2231]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jun 20 17:56:18 volumio-vm startx[2231]: (==) Log file: "/var/log/Xorg.0.log", Time: Fri Jun 20 17:56:18 2025 Jun 20 17:56:18 volumio-vm startx[2231]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jun 20 17:56:18 volumio-vm startx[2231]: vesa: Ignoring device with a bound kernel driver Jun 20 17:56:18 volumio-vm startx[2231]: (EE) Jun 20 17:56:18 volumio-vm startx[2231]: Fatal server error: Jun 20 17:56:18 volumio-vm startx[2231]: (EE) no screens found(EE) Jun 20 17:56:18 volumio-vm startx[2231]: (EE) Jun 20 17:56:18 volumio-vm startx[2231]: Please consult the The X.Org Foundation support Jun 20 17:56:18 volumio-vm startx[2231]: at http://wiki.x.org Jun 20 17:56:18 volumio-vm startx[2231]: for help. Jun 20 17:56:18 volumio-vm startx[2231]: (EE) Please also check the log file at "/var/log/Xorg.0.log" for additional information. Jun 20 17:56:18 volumio-vm startx[2231]: (EE) Jun 20 17:56:18 volumio-vm startx[2231]: (EE) Server terminated with error (1). Closing log file. Jun 20 17:56:18 volumio-vm sudo[2233]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f Jun 20 17:56:18 volumio-vm sudo[2233]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Jun 20 17:56:18 volumio-vm volumio-remote-updater[795]: [2025-06-20 17:56:18] [connect] Successful connection Jun 20 17:56:18 volumio-vm volumio-remote-updater[795]: [2025-06-20 17:56:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1750434978 101 Jun 20 17:56:18 volumio-vm volumio[2000]: 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: 2 Jun 20 17:56:20 volumio-vm volumio[2000]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 20 17:56:24 volumio-vm sudo[2254]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 20 17:56:24 volumio-vm sudo[2254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:24 volumio-vm sudo[2254]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:24 volumio-vm sudo[2259]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 20 17:56:24 volumio-vm sudo[2259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:24 volumio-vm sudo[2259]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:24 volumio-vm sudo[2265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 20 17:56:24 volumio-vm sudo[2265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:24 volumio-vm sudo[2265]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:24 volumio-vm volumio[2000]: info: Upmpdcli Daemon Started Jun 20 17:56:24 volumio-vm volumio[2000]: info: Discovery: adding 77a805a4-7797-49f6-864a-33f514278080 Jun 20 17:56:24 volumio-vm volumio[2000]: info: Discovery: Found device Volumio VM Jun 20 17:56:24 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:24 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:24 volumio-vm volumio[2000]: info: Discovery: this is already registered, 77a805a4-7797-49f6-864a-33f514278080 Jun 20 17:56:24 volumio-vm volumio[2000]: info: Discovery: Found device Volumio VM Jun 20 17:56:24 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:24 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:24 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:24 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:24 volumio-vm systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 20 17:56:24 volumio-vm dbus-daemon[789]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.49' (uid=0 pid=2270 comm="timedatectl show --property=NTPSynchronized --valu") Jun 20 17:56:24 volumio-vm systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 20 17:56:25 volumio-vm dbus-daemon[789]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 20 17:56:25 volumio-vm systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 20 17:56:25 volumio-vm setdatetime-helper.sh[2269]: Time is not synchronized. Attempting to sync... Jun 20 17:56:25 volumio-vm sudo[2278]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Fri, 20 Jun 2025 15:56:25 GMT#015' Jun 20 17:56:25 volumio-vm sudo[2278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 20 17:56:25 volumio-vm setdatetime-helper.sh[2279]: Fri Jun 20 17:56:25 CEST 2025 Jun 20 17:56:25 volumio-vm systemd-journald[478]: Time jumped backwards, rotating. Jun 20 17:56:25 volumio-vm setdatetime-helper.sh[2269]: Time synchronized successfully. Jun 20 17:56:25 volumio-vm sudo[2278]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:25 volumio-vm systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 20 17:56:25 volumio-vm systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 20 17:56:33 volumio-vm startx[2230]: xinit: giving up Jun 20 17:56:33 volumio-vm startx[2230]: xinit: unable to connect to X server: Connection refused Jun 20 17:56:33 volumio-vm startx[2230]: xinit: server error Jun 20 17:56:33 volumio-vm systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Jun 20 17:56:33 volumio-vm systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Jun 20 17:56:34 volumio-vm volumio[2000]: info: Discovery: this is already registered, 77a805a4-7797-49f6-864a-33f514278080 Jun 20 17:56:34 volumio-vm volumio[2000]: info: Discovery: Found device Volumio VM Jun 20 17:56:34 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:34 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:34 volumio-vm volumio[2000]: info: Discovery: this is already registered, 77a805a4-7797-49f6-864a-33f514278080 Jun 20 17:56:34 volumio-vm volumio[2000]: info: Discovery: Found device Volumio VM Jun 20 17:56:34 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:34 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:35 volumio-vm volumio[2000]: error: MyVolumio Plugin failed to start in a timely fashion Jun 20 17:56:35 volumio-vm volumio[2000]: [Metrics] CommandRouter: 20s 718.14ms Jun 20 17:56:35 volumio-vm volumio[2000]: info: CoreCommandRouter::volumiosetStartupVolume Jun 20 17:56:35 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:35 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:35 volumio-vm volumio[2000]: info: CoreCommandRouter::Close All Modals sent Jun 20 17:56:35 volumio-vm volumio[2000]: info: CoreCommandRouter::Close All Modals sent Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 20 17:56:35 volumio-vm volumio[2000]: info: Adding plugin bluetooth to MyMusic Plugins Jun 20 17:56:35 volumio-vm volumio[2000]: info: Adding plugin multiroom to MyMusic Plugins Jun 20 17:56:35 volumio-vm volumio[2000]: info: Adding plugin metavolumio to MyMusic Plugins Jun 20 17:56:35 volumio-vm volumio[2000]: info: Adding plugin cd_controller to MyMusic Plugins Jun 20 17:56:35 volumio-vm volumio[2000]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 20 17:56:35 volumio-vm volumio[2000]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 20 17:56:35 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:35 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:35 volumio-vm volumio[2000]: info: Starting MyVolumio Remote Streaming Endpoints Jun 20 17:56:35 volumio-vm volumio[2000]: info: MyVolumio login type: Token Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 20 17:56:35 volumio-vm volumio[2000]: info: Streaming services startup Jun 20 17:56:35 volumio-vm volumio[2000]: info: Starting Streaming Daemon Jun 20 17:56:35 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 20 17:56:35 volumio-vm sudo[2311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 20 17:56:35 volumio-vm sudo[2311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:35 volumio-vm sudo[2311]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:35 volumio-vm volumio[2000]: error: Cannot start Volumio Streaming Daemon Jun 20 17:56:35 volumio-vm volumio[2000]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 20 17:56:35 volumio-vm volumio[2000]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 20 17:56:36 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 20 17:56:36 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 20 17:56:36 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 20 17:56:36 volumio-vm volumio[2000]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 20 17:56:37 volumio-vm volumio[2000]: info: MyVolumio token set successfully Jun 20 17:56:37 volumio-vm volumio[2000]: info: MYVOLUMIO: Adding device Jun 20 17:56:37 volumio-vm volumio[2000]: info: MYVOLUMIO: Evaluating Server Jun 20 17:56:37 volumio-vm volumio[2000]: info: MyVolumio Plan changed: premium Jun 20 17:56:37 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Jun 20 17:56:37 volumio-vm volumio[2000]: info: Removing browser output: myVolumio user plan is not superstar Jun 20 17:56:37 volumio-vm volumio[2000]: info: Removing audio output: Jun 20 17:56:37 volumio-vm volumio[2000]: info: MYVOLUMIO: Adding device Jun 20 17:56:37 volumio-vm volumio[2000]: info: MYVOLUMIO: Evaluating Server Jun 20 17:56:37 volumio-vm volumio[2000]: info: Remote config written successfully Jun 20 17:56:37 volumio-vm volumio[2000]: info: Starting Tunnel 1 Jun 20 17:56:37 volumio-vm volumio[2000]: info: Starting Tunnel Connection Checker Jun 20 17:56:37 volumio-vm volumio[2000]: info: MYVolumio Device enabled Jun 20 17:56:37 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Jun 20 17:56:37 volumio-vm volumio[2000]: info: MyVolumio status changed Jun 20 17:56:37 volumio-vm volumio[2000]: info: Streaming services startup Jun 20 17:56:37 volumio-vm volumio[2000]: info: Starting Streaming Daemon Jun 20 17:56:37 volumio-vm sudo[2355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 20 17:56:37 volumio-vm sudo[2355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:37 volumio-vm sudo[2355]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:37 volumio-vm volumio[2000]: error: Cannot start Volumio Streaming Daemon Jun 20 17:56:37 volumio-vm volumio[2000]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 20 17:56:37 volumio-vm volumio[2000]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 20 17:56:37 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] Could not read cache file: ENOENT: no such file or directory, open '/data/myvolumio/cache.data' Jun 20 17:56:37 volumio-vm volumio[2000]: info: Setting Geolocation for MyVolumio to eu10 Jun 20 17:56:37 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:37 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:37 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:37 volumio-vm volumio[2000]: info: Setting Geolocation for MyVolumio to eu4 Jun 20 17:56:37 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:37 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:37 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:38 volumio-vm volumio[2000]: info: Successfully Added MyVolumio device Jun 20 17:56:38 volumio-vm systemd[1]: volumio-kiosk.service: Scheduled restart job, restart counter is at 5. Jun 20 17:56:38 volumio-vm systemd[1]: Stopped volumio-kiosk.service - Start Volumio Kiosk. Jun 20 17:56:38 volumio-vm systemd[1]: Started volumio-kiosk.service - Start Volumio Kiosk. Jun 20 17:56:38 volumio-vm startx[2379]: X.Org X Server 1.21.1.7 Jun 20 17:56:38 volumio-vm startx[2379]: X Protocol Version 11, Revision 0 Jun 20 17:56:38 volumio-vm startx[2379]: Current Operating System: Linux volumio-vm 6.12.30-volumio #2 SMP PREEMPT_DYNAMIC Wed May 28 19:37:30 BST 2025 x86_64 Jun 20 17:56:38 volumio-vm startx[2379]: Kernel command line: BOOT_IMAGE=vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=fe897e9c-0d5f-4cba-bc7b-576cf9309cc2 bootpart=UUID=E667-2E51 datapart=UUID=9654a8ab-19c6-439c-9b73-299d49ed7131 hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=vendor net.ifnames=0 use_kmsg=no initrd=volumio.initrd Jun 20 17:56:38 volumio-vm startx[2379]: xorg-server 2:21.1.7-3+deb12u9 (https://www.debian.org/support) Jun 20 17:56:38 volumio-vm startx[2379]: Current version of pixman: 0.42.2 Jun 20 17:56:38 volumio-vm startx[2379]: Before reporting problems, check http://wiki.x.org Jun 20 17:56:38 volumio-vm startx[2379]: to make sure that you have the latest version. Jun 20 17:56:38 volumio-vm startx[2379]: Markers: (--) probed, (**) from config file, (==) default setting, Jun 20 17:56:38 volumio-vm startx[2379]: (++) from command line, (!!) notice, (II) informational, Jun 20 17:56:38 volumio-vm startx[2379]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jun 20 17:56:38 volumio-vm startx[2379]: (==) Log file: "/var/log/Xorg.0.log", Time: Fri Jun 20 17:56:38 2025 Jun 20 17:56:38 volumio-vm startx[2379]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jun 20 17:56:38 volumio-vm startx[2379]: vesa: Ignoring device with a bound kernel driver Jun 20 17:56:38 volumio-vm startx[2379]: (EE) Jun 20 17:56:38 volumio-vm startx[2379]: Fatal server error: Jun 20 17:56:38 volumio-vm startx[2379]: (EE) no screens found(EE) Jun 20 17:56:38 volumio-vm startx[2379]: (EE) Jun 20 17:56:38 volumio-vm startx[2379]: Please consult the The X.Org Foundation support Jun 20 17:56:38 volumio-vm startx[2379]: at http://wiki.x.org Jun 20 17:56:38 volumio-vm startx[2379]: for help. Jun 20 17:56:38 volumio-vm startx[2379]: (EE) Please also check the log file at "/var/log/Xorg.0.log" for additional information. Jun 20 17:56:38 volumio-vm startx[2379]: (EE) Jun 20 17:56:38 volumio-vm startx[2379]: (EE) Server terminated with error (1). Closing log file. Jun 20 17:56:38 volumio-vm volumio[2000]: info: Successfully Added MyVolumio device Jun 20 17:56:38 volumio-vm volumio[2000]: info: Updating MyVolumio device info Jun 20 17:56:38 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:38 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:38 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:38 volumio-vm volumio[2000]: info: Updating MyVolumio device info Jun 20 17:56:38 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:38 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:38 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Plugin music_service/qobuzconnect is enabled for this plan, but could not be found on the local filesystem! Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] The plugin audio_interface/multiroom failed to load, setting it to stopped. Error: Error: ENOSPC: no space left on device, mkdir '/data/configuration/audio_interface/multiroom' Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm sudo[2383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Jun 20 17:56:39 volumio-vm sudo[2383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm sudo[2383]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: MultiRoom plugin initialized Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: STOPPING SNAPCLIENT Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: Snap server stop Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: STOPPING volumioStreaming Jun 20 17:56:39 volumio-vm sudo[2400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Jun 20 17:56:39 volumio-vm sudo[2400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Jun 20 17:56:39 volumio-vm sudo[2404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Jun 20 17:56:39 volumio-vm sudo[2403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Jun 20 17:56:39 volumio-vm sudo[2404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm sudo[2403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] The plugin miscellanea/metavolumio failed to load, setting it to stopped. Error: Error: ENOSPC: no space left on device, mkdir '/data/configuration/miscellanea/metavolumio' Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Jun 20 17:56:39 volumio-vm sudo[2407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jun 20 17:56:39 volumio-vm sudo[2407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm sudo[2404]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] The plugin miscellanea/manifestui failed to load, setting it to stopped. Error: Error: ENOSPC: no space left on device, mkdir '/data/configuration/miscellanea/manifestui' Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Jun 20 17:56:39 volumio-vm sudo[2407]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] The plugin music_service/cd_controller failed to load, setting it to stopped. Error: Error: ENOSPC: no space left on device, mkdir '/data/configuration/music_service/cd_controller' Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Jun 20 17:56:39 volumio-vm sudo[2400]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Jun 20 17:56:39 volumio-vm sudo[2403]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] The plugin music_service/hi_res_audio failed to load, setting it to stopped. Error: Error: ENOSPC: no space left on device, mkdir '/data/configuration/music_service/hi_res_audio' Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] The plugin music_service/tidal failed to load, setting it to stopped. Error: Error: ENOSPC: no space left on device, mkdir '/data/configuration/music_service/tidal' Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] The plugin music_service/qobuz failed to load, setting it to stopped. Error: Error: ENOSPC: no space left on device, mkdir '/data/configuration/music_service/qobuz' Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] !!!! WARNING !!!! Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Jun 20 17:56:39 volumio-vm volumio[2000]: info: Preparing to generate the ALSA configuration file Jun 20 17:56:39 volumio-vm volumio[2000]: error: [MyVolumio PluginManager] Could not create cache dir /data/myvolumio/: ENOSPC: no space left on device, mkdir '/data/myvolumio/' Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: Removed streaming files Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: volumioStreaming STOPPED Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: SNAPSERVER STOPPED Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: SNAPCLIENT STOPPED Jun 20 17:56:39 volumio-vm volumio[2000]: info: Asound.conf file unchanged, so no further update is needed Jun 20 17:56:39 volumio-vm volumio[2000]: info: Output device has changed, restarting MPD Jun 20 17:56:39 volumio-vm volumio[2000]: info: Output device has changed, restarting Shairport Sync Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:39 volumio-vm sudo[2412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 20 17:56:39 volumio-vm sudo[2412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm sudo[2414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 20 17:56:39 volumio-vm sudo[2414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm sudo[2412]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm systemd[1]: Stopping mpd.service - Music Player Daemon... Jun 20 17:56:39 volumio-vm volumio[2000]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: [FUNC] onStart Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output for this device Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output Jun 20 17:56:39 volumio-vm systemd[1]: mpd.service: Deactivated successfully. Jun 20 17:56:39 volumio-vm systemd[1]: Stopped mpd.service - Music Player Daemon. Jun 20 17:56:39 volumio-vm systemd[1]: mpd.socket: Deactivated successfully. Jun 20 17:56:39 volumio-vm systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jun 20 17:56:39 volumio-vm systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding audio output: Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding audio output: Jun 20 17:56:39 volumio-vm volumio[2000]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding METAVOLUMIO REST API Endpoints Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Jun 20 17:56:39 volumio-vm volumio[2000]: info: Preparing CD Folders Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding CD REST API Endpoints Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jun 20 17:56:39 volumio-vm volumio[2000]: info: Starting UDEV Watcher for CD Jun 20 17:56:39 volumio-vm volumio[2000]: info: Detecting CD presence with UDEV Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding inputs REST Endpoints Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jun 20 17:56:39 volumio-vm volumio[2000]: info: Scanning Audio Inputs Jun 20 17:56:39 volumio-vm volumio[2000]: info: Checking against Known Cards name Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 20 17:56:39 volumio-vm volumio[2000]: info: [1750434999362] CoreMusicLibrary::Adding element HDA Intel Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 20 17:56:39 volumio-vm volumio[2000]: Cannot find translation for source HDA Intel Jun 20 17:56:39 volumio-vm volumio[2000]: info: Checking against Known Cards name Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding Server instance for streaming Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Jun 20 17:56:39 volumio-vm volumio[2000]: error: Hi Res Audio Failed Login: Missing Login Data Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding HIGHRESAUDIO REST API Endpoints Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Jun 20 17:56:39 volumio-vm volumio[2000]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Jun 20 17:56:39 volumio-vm systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jun 20 17:56:39 volumio-vm volumio[2000]: info: Stopping AccessToken refresher cron Jun 20 17:56:39 volumio-vm systemd[1]: Starting mpd.service - Music Player Daemon... Jun 20 17:56:39 volumio-vm sudo[2433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 20 17:56:39 volumio-vm sudo[2433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm volumio[2000]: info: AccessToken refresher cron started Jun 20 17:56:39 volumio-vm volumio[2000]: info: Stopping AccessToken refresher cron for QOBUZ Jun 20 17:56:39 volumio-vm systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Jun 20 17:56:39 volumio-vm volumio[2000]: info: AccessToken refresher cron started for QOBUZ Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding TIDAL REST API Endpoints Jun 20 17:56:39 volumio-vm volumio[2000]: info: Adding QOBUZ REST API Endpoints Jun 20 17:56:39 volumio-vm systemd[1]: vtcs.service: Deactivated successfully. Jun 20 17:56:39 volumio-vm systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Jun 20 17:56:39 volumio-vm sudo[2433]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm sudo[2434]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 20 17:56:39 volumio-vm volumio[2000]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: Failed to power on adapter: Jun 20 17:56:39 volumio-vm volumio[2000]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Jun 20 17:56:39 volumio-vm volumio[2000]: info: MPD Permissions set Jun 20 17:56:39 volumio-vm volumio[2000]: error: Cannot create CDDB Folder at /data/cddb: Error: ENOSPC: no space left on device, mkdir '/data/cddb' Jun 20 17:56:39 volumio-vm volumio[2000]: info: Successfully Updated MyVolumio device Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:39 volumio-vm sudo[2434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 20 17:56:39 volumio-vm sudo[2434]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: info: Starting Shairport Sync Jun 20 17:56:39 volumio-vm sudo[2438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jun 20 17:56:39 volumio-vm sudo[2449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 20 17:56:39 volumio-vm sudo[2449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm volumio[2000]: error: Could Not Write Alsa Configuration File: Error: ENOSPC: no space left on device, mkdir '/data/configuration/audio_interface/multiroom' Jun 20 17:56:39 volumio-vm volumio[2000]: error: Could Not Write Alsa Configuration File: Error: ENOSPC: no space left on device, mkdir '/data/configuration/audio_interface/multiroom' Jun 20 17:56:39 volumio-vm sudo[2438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jun 20 17:56:39 volumio-vm systemd[1]: shairport-sync.service: Deactivated successfully. Jun 20 17:56:39 volumio-vm systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 20 17:56:39 volumio-vm systemd[1]: shairport-sync.service: Consumed 1.689s CPU time. Jun 20 17:56:39 volumio-vm systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 20 17:56:39 volumio-vm sudo[2449]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Jun 20 17:56:39 volumio-vm sudo[2438]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: info: Shairport-Sync Started Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioStop Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreStateMachine::stop Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 20 17:56:39 volumio-vm volumio[2000]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Jun 20 17:56:39 volumio-vm volumio[2000]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 20 17:56:39 volumio-vm volumiobt[2456]: INFO [BTSTART] Ensuring Bluetooth directory exists... Jun 20 17:56:39 volumio-vm sudo[2457]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Jun 20 17:56:39 volumio-vm sudo[2457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm sudo[2457]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm sudo[2473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Jun 20 17:56:39 volumio-vm sudo[2473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:39 volumio-vm sudo[2473]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumiobt[2475]: INFO [BTSTART] Powering on Bluetooth if needed... Jun 20 17:56:39 volumio-vm volumiobt[2478]: No default controller available Jun 20 17:56:39 volumio-vm mpd[2450]: 2025-06-20T17:56:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 20 17:56:39 volumio-vm systemd[1]: Started mpd.service - Music Player Daemon. Jun 20 17:56:39 volumio-vm sudo[2414]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:39 volumio-vm volumio[2000]: error: updateQueue error: null Jun 20 17:56:39 volumio-vm volumio[2000]: info: Successfully Updated MyVolumio device Jun 20 17:56:40 volumio-vm volumiobt[2483]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Jun 20 17:56:40 volumio-vm volumiobt[2484]: [75B blob data] Jun 20 17:56:40 volumio-vm volumiobt[2484]: No default controller available Jun 20 17:56:40 volumio-vm volumiobt[2484]: [bluetooth]# pairable on Jun 20 17:56:40 volumio-vm volumiobt[2484]: No default controller available Jun 20 17:56:40 volumio-vm volumiobt[2484]: [54B blob data] Jun 20 17:56:40 volumio-vm volumiobt[2484]: [bluetooth]# Jun 20 17:56:40 volumio-vm volumiobt[2485]: INFO [BTSTART] Registering Bluetooth agent... Jun 20 17:56:40 volumio-vm volumiobt[2487]: No agent is registered Jun 20 17:56:40 volumio-vm volumiobt[2488]: INFO [BTSTART] Agent registered successfully. Jun 20 17:56:40 volumio-vm volumiobt[2489]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Jun 20 17:56:40 volumio-vm volumiobt[2490]: INFO:a2dp-agent:Connecting to system bus. Jun 20 17:56:40 volumio-vm volumiobt[2490]: ERROR:a2dp-agent:No Bluetooth adapter found: Bluetooth adapter not found Jun 20 17:56:40 volumio-vm volumiobt[2493]: INFO [BTSTART] Disconnecting all Bluetooth devices... Jun 20 17:56:40 volumio-vm volumiobt[2498]: INFO [BTSTART] Unregistering Bluetooth agent... Jun 20 17:56:40 volumio-vm volumiobt[2499]: No agent is registered Jun 20 17:56:40 volumio-vm volumiobt[2500]: INFO [BTSTART] Stopping bluealsa-aplay (if any)... Jun 20 17:56:40 volumio-vm volumiobt[2502]: INFO [BTSTART] Stopping A2DP agent (a2dp-agent)... Jun 20 17:56:40 volumio-vm systemd[1]: volumiobt.service: Deactivated successfully. Jun 20 17:56:42 volumio-vm volumio[2000]: info: BOOT COMPLETED Jun 20 17:56:42 volumio-vm volumio[2000]: info: TidalConnect service stoped! Jun 20 17:56:42 volumio-vm volumio[2000]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 20 17:56:42 volumio-vm volumio[2000]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 20 17:56:42 volumio-vm sudo[2514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 20 17:56:42 volumio-vm sudo[2514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:42 volumio-vm systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Jun 20 17:56:42 volumio-vm sudo[2514]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:42 volumio-vm volumio[2000]: info: Executing endpoint tc_getconfig Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jun 20 17:56:42 volumio-vm vtcs[2517]: OpenSSL version mismatch. Built against 101010ef, you have 30000100 Jun 20 17:56:42 volumio-vm vtcs[2517]: STARTING TidalConnect services, version: 1.5.0.45 Jun 20 17:56:42 volumio-vm vtcs[2517]: STARTED TidalConnect services. Jun 20 17:56:42 volumio-vm volumio[2000]: info: Executing endpoint tc_connect Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Jun 20 17:56:42 volumio-vm volumio[2000]: info: Connecting to TidalConnect Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::servicePushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output update for this device Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output Jun 20 17:56:42 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:42 volumio-vm volumio[2000]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Jun 20 17:56:42 volumio-vm volumio[2000]: verbose: CURRENT POSITION 0 Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::syncState stateService stop Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::syncState currentStatus stop Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output update for this device Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output Jun 20 17:56:42 volumio-vm volumio[2000]: info: No code Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output update for this device Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::servicePushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output update for this device Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output Jun 20 17:56:42 volumio-vm volumio[2000]: info: CorePlayQueue::getTrack 0 Jun 20 17:56:42 volumio-vm volumio[2000]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Jun 20 17:56:42 volumio-vm vtcs[2517]: [2025-06-20 17:56:42.469] [tisoc] [error] [WebsocketServerTls.cpp:90] [WebsocketServerTls onTlsInit Error] use_certificate_chain: no start line Jun 20 17:56:42 volumio-vm volumio[2000]: verbose: CURRENT POSITION 0 Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::syncState stateService stop Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::syncState currentStatus stop Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output update for this device Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output Jun 20 17:56:42 volumio-vm volumio[2000]: info: No code Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreStateMachine::pushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioPushState Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output update for this device Jun 20 17:56:42 volumio-vm volumio[2000]: info: MRS: Pushing multiroomSync output Jun 20 17:56:42 volumio-vm sudo[2540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jun 20 17:56:42 volumio-vm sudo[2540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:42 volumio-vm autossh[1676]: received signal to exit (15) Jun 20 17:56:42 volumio-vm systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Jun 20 17:56:42 volumio-vm systemd[1]: sshtunnel.service: Deactivated successfully. Jun 20 17:56:42 volumio-vm systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Jun 20 17:56:42 volumio-vm systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Jun 20 17:56:42 volumio-vm sudo[2540]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:42 volumio-vm volumio[2000]: info: Remote SSH Started Jun 20 17:56:42 volumio-vm autossh[2543]: port set to 0, monitoring disabled Jun 20 17:56:42 volumio-vm autossh[2543]: starting ssh (count 1) Jun 20 17:56:42 volumio-vm autossh[2543]: ssh child pid is 2546 Jun 20 17:56:42 volumio-vm volumio[2000]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 20 17:56:42 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:42 volumio-vm volumio[2000]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.wCm8Y6WpLcSGPBG9FBLtifV44Vi2.bb679819e8b09e63679f898b046529bb.state.status' Jun 20 17:56:42 volumio-vm volumiossh-tunnel[2546]: Warning: Permanently added '[eu4.myvolumio.org]:2222' (RSA) to the list of known hosts. Jun 20 17:56:44 volumio-vm volumio[2000]: info: MRS: Getting audio outputs on start Jun 20 17:56:44 volumio-vm volumio[2000]: info: MRS: Requesting all other devices output Jun 20 17:56:44 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 20 17:56:44 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 20 17:56:44 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 20 17:56:44 volumio-vm volumio-remote-updater[795]: Test mode disabled Jun 20 17:56:44 volumio-vm volumio-remote-updater[795]: Alpha mode disabled Jun 20 17:56:44 volumio-vm volumio-remote-updater[795]: Alpha legacy test mode disabled Jun 20 17:56:44 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 20 17:56:45 volumio-vm volumio[2000]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 20 17:56:45 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 20 17:56:45 volumio-vm volumio[2000]: info: TidalConnect service started! Jun 20 17:56:50 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 20 17:56:50 volumio-vm volumio[2000]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jun 20 17:56:50 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:52 volumio-vm sudo[2575]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 20 17:56:52 volumio-vm sudo[2575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:52 volumio-vm sudo[2575]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:52 volumio-vm sudo[2578]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 20 17:56:52 volumio-vm sudo[2578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:52 volumio-vm sudo[2578]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:52 volumio-vm volumio[2000]: verbose: New Socket.io Connection to 192.168.100.217 from 192.168.100.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jun 20 17:56:52 volumio-vm sudo[2584]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 20 17:56:52 volumio-vm sudo[2585]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 20 17:56:52 volumio-vm sudo[2585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:52 volumio-vm sudo[2584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 20 17:56:52 volumio-vm sudo[2584]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:52 volumio-vm sudo[2585]: pam_unix(sudo:session): session closed for user root Jun 20 17:56:52 volumio-vm volumio[2000]: verbose: New Socket.io Connection to 192.168.100.217 from 192.168.100.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetVisibleSources Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 20 17:56:52 volumio-vm volumio[2000]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 20 17:56:52 volumio-vm volumio[2000]: info: Received Get System Info Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 20 17:56:52 volumio-vm volumio[2000]: info: Discovery: Getting this device information Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:52 volumio-vm volumio[2000]: info: Listing playlists Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 20 17:56:52 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 20 17:56:53 volumio-vm startx[2378]: xinit: giving up Jun 20 17:56:53 volumio-vm startx[2378]: xinit: unable to connect to X server: Connection refused Jun 20 17:56:53 volumio-vm startx[2378]: xinit: server error Jun 20 17:56:53 volumio-vm systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Jun 20 17:56:53 volumio-vm systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Jun 20 17:56:53 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:54 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 20 17:56:54 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 20 17:56:54 volumio-vm volumio[2000]: info: Received Get System Info Jun 20 17:56:54 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 20 17:56:54 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 20 17:56:54 volumio-vm volumio[2000]: info: Discovery: Getting this device information Jun 20 17:56:54 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:54 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 20 17:56:54 volumio-vm systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 20 17:56:55 volumio-vm volumio[2000]: info: Retrieving Cloud Streaming UI Jun 20 17:56:55 volumio-vm volumio[2000]: info: Getting Tidal Cloud Configuration Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 20 17:56:55 volumio-vm volumio[2000]: info: Getting Qobuz Cloud Configuration Jun 20 17:56:55 volumio-vm volumio[2000]: info: Asking plugin for UI Config Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 20 17:56:55 volumio-vm volumio[2000]: info: Getting Spotify Cloud Configuration Jun 20 17:56:55 volumio-vm volumio[2000]: info: Asking plugin for UI Config Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 20 17:56:55 volumio-vm volumio[2000]: info: Saving Spotify Acccount Jun 20 17:56:55 volumio-vm volumio[2000]: info: Got it Jun 20 17:56:55 volumio-vm volumio[2000]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 20 17:56:55 volumio-vm volumio[2000]: info: Got Tidal Cloud Configuration Jun 20 17:56:55 volumio-vm volumio[2000]: info: Got it Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetBrowseSources Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetBrowseSources Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetBrowseSources Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetBrowseSources Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 20 17:56:55 volumio-vm volumio[2000]: info: Executing endpoint metavolumio Jun 20 17:56:55 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 20 17:56:56 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 20 17:56:56 volumio-vm volumio[2000]: info: Received Get System Info Jun 20 17:56:56 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 20 17:56:56 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 20 17:56:56 volumio-vm volumio[2000]: info: Discovery: Getting this device information Jun 20 17:56:56 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:56:56 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 20 17:56:58 volumio-vm systemd[1]: volumio-kiosk.service: Scheduled restart job, restart counter is at 6. Jun 20 17:56:58 volumio-vm systemd[1]: Stopped volumio-kiosk.service - Start Volumio Kiosk. Jun 20 17:56:58 volumio-vm systemd[1]: Started volumio-kiosk.service - Start Volumio Kiosk. Jun 20 17:56:58 volumio-vm startx[2643]: X.Org X Server 1.21.1.7 Jun 20 17:56:58 volumio-vm startx[2643]: X Protocol Version 11, Revision 0 Jun 20 17:56:58 volumio-vm startx[2643]: Current Operating System: Linux volumio-vm 6.12.30-volumio #2 SMP PREEMPT_DYNAMIC Wed May 28 19:37:30 BST 2025 x86_64 Jun 20 17:56:58 volumio-vm startx[2643]: Kernel command line: BOOT_IMAGE=vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=fe897e9c-0d5f-4cba-bc7b-576cf9309cc2 bootpart=UUID=E667-2E51 datapart=UUID=9654a8ab-19c6-439c-9b73-299d49ed7131 hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=vendor net.ifnames=0 use_kmsg=no initrd=volumio.initrd Jun 20 17:56:58 volumio-vm startx[2643]: xorg-server 2:21.1.7-3+deb12u9 (https://www.debian.org/support) Jun 20 17:56:58 volumio-vm startx[2643]: Current version of pixman: 0.42.2 Jun 20 17:56:58 volumio-vm startx[2643]: Before reporting problems, check http://wiki.x.org Jun 20 17:56:58 volumio-vm startx[2643]: to make sure that you have the latest version. Jun 20 17:56:58 volumio-vm startx[2643]: Markers: (--) probed, (**) from config file, (==) default setting, Jun 20 17:56:58 volumio-vm startx[2643]: (++) from command line, (!!) notice, (II) informational, Jun 20 17:56:58 volumio-vm startx[2643]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jun 20 17:56:58 volumio-vm startx[2643]: (==) Log file: "/var/log/Xorg.0.log", Time: Fri Jun 20 17:56:58 2025 Jun 20 17:56:58 volumio-vm startx[2643]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jun 20 17:56:58 volumio-vm startx[2643]: vesa: Ignoring device with a bound kernel driver Jun 20 17:56:58 volumio-vm startx[2643]: (EE) Jun 20 17:56:58 volumio-vm startx[2643]: Fatal server error: Jun 20 17:56:58 volumio-vm startx[2643]: (EE) no screens found(EE) Jun 20 17:56:58 volumio-vm startx[2643]: (EE) Jun 20 17:56:58 volumio-vm startx[2643]: Please consult the The X.Org Foundation support Jun 20 17:56:58 volumio-vm startx[2643]: at http://wiki.x.org Jun 20 17:56:58 volumio-vm startx[2643]: for help. Jun 20 17:56:58 volumio-vm startx[2643]: (EE) Please also check the log file at "/var/log/Xorg.0.log" for additional information. Jun 20 17:56:58 volumio-vm startx[2643]: (EE) Jun 20 17:56:58 volumio-vm startx[2643]: (EE) Server terminated with error (1). Closing log file. Jun 20 17:57:00 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetState Jun 20 17:57:00 volumio-vm volumio[2000]: info: CoreCommandRouter::volumioGetQueue Jun 20 17:57:00 volumio-vm volumio[2000]: info: CoreStateMachine::getQueue Jun 20 17:57:00 volumio-vm volumio[2000]: info: CorePlayQueue::getQueue Jun 20 17:57:02 volumio-vm volumio[2000]: info: Executing endpoint metavolumio Jun 20 17:57:02 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 20 17:57:02 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 20 17:57:04 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 20 17:57:04 volumio-vm volumio[2000]: info: Preload queue cleared Jun 20 17:57:07 volumio-vm volumio[2000]: Searching plugin music_service/webradio Jun 20 17:57:07 volumio-vm volumio[2000]: info: CoreCommandRouter::executeOnPlugin: webradio , search Jun 20 17:57:07 volumio-vm volumio[2000]: Use XMLElement.setAttribute instead Jun 20 17:57:07 volumio-vm volumio[2000]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 20 17:57:07 volumio-vm volumio[2000]: TypeError: xmlGetAttribute(...).value is not a function Jun 20 17:57:07 volumio-vm volumio[2000]: at /volumio/app/plugins/music_service/webradio/index.js:966:57 Jun 20 17:57:07 volumio-vm volumio[2000]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 20 17:57:07 volumio-vm volumio[2000]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 20 17:57:07 volumio-vm sudo[2681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-20 17:56' Jun 20 17:57:07 volumio-vm sudo[2681]: 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="cee9bb5b0ee50e4898478097a64b5c6c77d5a212" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 14 07:01:29 UTC 2025" VOLUMIO_VERSION="4.012" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="38c4f0e007cb9b6482e9f27bbe65b0b5"