Oct 31 16:44:00 volumio-vx86 volumio[909]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 31 16:44:00 volumio-vx86 volumio[909]: info: MyVolumio token set successfully Oct 31 16:44:00 volumio-vx86 volumio[909]: info: MYVOLUMIO: Adding device Oct 31 16:44:00 volumio-vx86 volumio[909]: info: MYVOLUMIO: Evaluating Server Oct 31 16:44:01 volumio-vx86 volumio[909]: info: MyVolumio Plan changed: superstar Oct 31 16:44:01 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:01 volumio-vx86 volumio[909]: info: MYVOLUMIO: Adding device Oct 31 16:44:01 volumio-vx86 volumio[909]: info: MYVOLUMIO: Evaluating Server Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Remote config written successfully Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Starting Tunnel 1 Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Starting Tunnel Connection Checker Oct 31 16:44:01 volumio-vx86 volumio[909]: info: MYVolumio Device disabled Oct 31 16:44:01 volumio-vx86 volumio[909]: info: MyVolumio status changed Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Streaming services startup Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Starting Streaming Daemon Oct 31 16:44:01 volumio-vx86 sudo[2547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 31 16:44:01 volumio-vx86 sudo[2547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Setting Geolocation for MyVolumio to eu2 Oct 31 16:44:01 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:01 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:01 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:01 volumio-vx86 sudo[2547]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:01 volumio-vx86 volumio[909]: error: Cannot start Volumio Streaming Daemon Oct 31 16:44:01 volumio-vx86 volumio[909]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 31 16:44:01 volumio-vx86 volumio[909]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Setting Geolocation for MyVolumio to eu9 Oct 31 16:44:01 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:01 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:01 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:01 volumio-vx86 volumio[909]: info: MYVolumio Device disabled Oct 31 16:44:01 volumio-vx86 volumio[909]: info: Successfully Added MyVolumio device Oct 31 16:44:02 volumio-vx86 volumio[909]: info: Successfully Added MyVolumio device Oct 31 16:44:02 volumio-vx86 volumio[909]: info: Updating MyVolumio device info Oct 31 16:44:02 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:02 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:02 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:02 volumio-vx86 volumio[909]: info: Updating MyVolumio device info Oct 31 16:44:02 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:02 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:02 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:02 volumio-vx86 volumio[909]: info: Successfully Updated MyVolumio device Oct 31 16:44:03 volumio-vx86 volumio[909]: info: Successfully Updated MyVolumio device Oct 31 16:44:06 volumio-vx86 sudo[2574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 31 16:44:06 volumio-vx86 sudo[2574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:06 volumio-vx86 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 31 16:44:06 volumio-vx86 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 31 16:44:06 volumio-vx86 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Oct 31 16:44:06 volumio-vx86 sudo[2574]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:06 volumio-vx86 volumio[909]: info: Remote SSH Started Oct 31 16:44:06 volumio-vx86 autossh[2577]: port set to 0, monitoring disabled Oct 31 16:44:06 volumio-vx86 autossh[2577]: starting ssh (count 1) Oct 31 16:44:06 volumio-vx86 autossh[2577]: ssh child pid is 2580 Oct 31 16:44:06 volumio-vx86 volumio[909]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 31 16:44:06 volumio-vx86 volumiossh-tunnel[2580]: Warning: Permanently added '[eu9.myvolumio.org]:2222' (RSA) to the list of known hosts. Oct 31 16:44:06 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:06 volumio-vx86 volumio[909]: info: CorePlayQueue::getTrack 0 Oct 31 16:44:30 volumio-vx86 volumio[909]: info: MYVolumio Device enabled Oct 31 16:44:30 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Oct 31 16:44:30 volumio-vx86 volumio[909]: info: MyVolumio status changed Oct 31 16:44:30 volumio-vx86 volumio[909]: info: Streaming services startup Oct 31 16:44:30 volumio-vx86 volumio[909]: info: Starting Streaming Daemon Oct 31 16:44:30 volumio-vx86 volumio[909]: error: [MyVolumio PluginManager] Could not read cache file: ENOENT: no such file or directory, open '/data/myvolumio/cache.data' Oct 31 16:44:30 volumio-vx86 sudo[2641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 31 16:44:30 volumio-vx86 sudo[2641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:30 volumio-vx86 sudo[2641]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:30 volumio-vx86 volumio[909]: error: Cannot start Volumio Streaming Daemon Oct 31 16:44:30 volumio-vx86 volumio[909]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 31 16:44:30 volumio-vx86 volumio[909]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 31 16:44:31 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Oct 31 16:44:31 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Oct 31 16:44:31 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Oct 31 16:44:32 volumio-vx86 sudo[2647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Oct 31 16:44:32 volumio-vx86 sudo[2647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:32 volumio-vx86 sudo[2647]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: MultiRoom plugin initialized Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: STOPPING SNAPCLIENT Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: Snap server stop Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: STOPPING volumioStreaming Oct 31 16:44:32 volumio-vx86 sudo[2665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Oct 31 16:44:32 volumio-vx86 sudo[2665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Oct 31 16:44:32 volumio-vx86 sudo[2667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Oct 31 16:44:32 volumio-vx86 sudo[2667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:32 volumio-vx86 sudo[2670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Oct 31 16:44:32 volumio-vx86 sudo[2670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:32 volumio-vx86 sudo[2665]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:32 volumio-vx86 sudo[2672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Oct 31 16:44:32 volumio-vx86 sudo[2672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:32 volumio-vx86 sudo[2667]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:32 volumio-vx86 sudo[2672]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Oct 31 16:44:32 volumio-vx86 sudo[2670]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Oct 31 16:44:32 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Oct 31 16:44:32 volumio-vx86 volumio[909]: info: Preparing to generate the ALSA configuration file Oct 31 16:44:32 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: Removed streaming files Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: volumioStreaming STOPPED Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: SNAPSERVER STOPPED Oct 31 16:44:32 volumio-vx86 volumio[909]: info: MRS: SNAPCLIENT STOPPED Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Asound.conf file unchanged, so no further update is needed Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Output device has changed, restarting MPD Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Output device has changed, restarting Shairport Sync Oct 31 16:44:33 volumio-vx86 sudo[2680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 16:44:33 volumio-vx86 sudo[2681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 16:44:33 volumio-vx86 sudo[2680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:33 volumio-vx86 sudo[2681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:33 volumio-vx86 sudo[2680]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:33 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:33 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:33 volumio-vx86 systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 16:44:33 volumio-vx86 volumio[909]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 31 16:44:33 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:33 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Oct 31 16:44:33 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: [FUNC] onStart Oct 31 16:44:33 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Oct 31 16:44:33 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Oct 31 16:44:33 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Oct 31 16:44:33 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Oct 31 16:44:33 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Oct 31 16:44:33 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Oct 31 16:44:33 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output for this device Oct 31 16:44:33 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:33 volumio-vx86 volumio[909]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 31 16:44:33 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:33 volumio-vx86 systemd[1]: mpd.service: Deactivated successfully. Oct 31 16:44:33 volumio-vx86 systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 31 16:44:33 volumio-vx86 systemd[1]: mpd.socket: Deactivated successfully. Oct 31 16:44:33 volumio-vx86 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 31 16:44:33 volumio-vx86 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 31 16:44:33 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Oct 31 16:44:33 volumio-vx86 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 31 16:44:33 volumio-vx86 systemd[1]: Starting mpd.service - Music Player Daemon... Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding METAVOLUMIO REST API Endpoints Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Oct 31 16:44:33 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Oct 31 16:44:33 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Preparing CD Folders Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding CD REST API Endpoints Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Starting UDEV Watcher for CD Oct 31 16:44:33 volumio-vx86 volumio[909]: info: Detecting CD presence with UDEV Oct 31 16:44:33 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Oct 31 16:44:33 volumio-vx86 sudo[2699]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 31 16:44:33 volumio-vx86 sudo[2699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 16:44:33 volumio-vx86 sudo[2699]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:33 volumio-vx86 mpd[2705]: 2025-10-31T16:44:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 31 16:44:33 volumio-vx86 systemd[1]: Started mpd.service - Music Player Daemon. Oct 31 16:44:33 volumio-vx86 sudo[2681]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:35 volumio-vx86 ntpd[823]: CLOCK: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 31 16:44:38 volumio-vx86 volumio[909]: warn: [cd-plugin] cdspeedctl: device or media not ready Oct 31 16:44:38 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding inputs REST Endpoints Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Scanning Audio Inputs Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Checking against Known Cards name Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 16:44:38 volumio-vx86 volumio[909]: info: [1761929078400] CoreMusicLibrary::Adding element Intel 82801AA-ICH Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 16:44:38 volumio-vx86 volumio[909]: Cannot find translation for source Intel 82801AA-ICH Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Checking against Known Cards name Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Checking against Known Cards name Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding Server instance for streaming Oct 31 16:44:38 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Oct 31 16:44:38 volumio-vx86 volumio[909]: error: Hi Res Audio Failed Login: Missing Login Data Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding HIGHRESAUDIO REST API Endpoints Oct 31 16:44:38 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Oct 31 16:44:38 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Oct 31 16:44:38 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Oct 31 16:44:38 volumio-vx86 volumio[909]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Oct 31 16:44:38 volumio-vx86 sudo[2731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 31 16:44:38 volumio-vx86 sudo[2731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: QobuzConnect: Starting Qobuz Connect socket and service Oct 31 16:44:38 volumio-vx86 sudo[2731]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:38 volumio-vx86 sudo[2739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 31 16:44:38 volumio-vx86 sudo[2739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:38 volumio-vx86 sudo[2739]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:38 volumio-vx86 volumio[909]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Stopping AccessToken refresher cron Oct 31 16:44:38 volumio-vx86 sudo[2741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 31 16:44:38 volumio-vx86 sudo[2741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:38 volumio-vx86 volumio[909]: info: AccessToken refresher cron started Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Stopping AccessToken refresher cron for QOBUZ Oct 31 16:44:38 volumio-vx86 volumio[909]: info: AccessToken refresher cron started for QOBUZ Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding TIDAL REST API Endpoints Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding QOBUZ REST API Endpoints Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Getting audio outputs on start Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Requesting all other devices output Oct 31 16:44:38 volumio-vx86 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 31 16:44:38 volumio-vx86 sudo[2741]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Adding multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Adding multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Adding multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Adding multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Adding multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Adding audio output: Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:38 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: Failed to power on adapter: Oct 31 16:44:38 volumio-vx86 volumio[909]: info: MPD Permissions set Oct 31 16:44:38 volumio-vx86 sudo[2745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Oct 31 16:44:38 volumio-vx86 sudo[2745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:38 volumio-vx86 systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Oct 31 16:44:38 volumio-vx86 sudo[2745]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:38 volumio-vx86 volumiobt[2749]: INFO [BTSTART] Ensuring Bluetooth directory exists... Oct 31 16:44:38 volumio-vx86 sudo[2750]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Oct 31 16:44:38 volumio-vx86 sudo[2750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:38 volumio-vx86 sudo[2750]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:38 volumio-vx86 volumio[909]: info: Executing endpoint qc_getconfig Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Oct 31 16:44:38 volumio-vx86 sudo[2752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Oct 31 16:44:38 volumio-vx86 sudo[2752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:38 volumio-vx86 sudo[2752]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:38 volumio-vx86 volumiobt[2756]: INFO [BTSTART] Powering on Bluetooth if needed... Oct 31 16:44:38 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:38.981 [2743.2743] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:38 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumiobt[2761]: No default controller available Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.056 [2743.2743] INFO VolumeManager: [0x556541af8b30]: Setting new playback volume: 75 Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.057 [2743.2743] INFO VolumeManager: [0x556541af8b30]: Setting new mute state: 0 Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.057 [2743.2743] INFO QobuzConnect: [0x556541af9d50]: Client initialized! Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.058 [2743.2743] INFO SampleApp: Starting Avahi advertising, name: Volumio-vx86, service name: _qobuz-connect._tcp Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.063 [2743.2743] INFO LocalConfigManager: [0x556541af7e20]: Starting Local Configuration server Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.064 [2743.2743] INFO SampleApp: Starting Local configuration server Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.064 [2743.2743] INFO SampleApp: Connected to UNIX socket client 0x556541acebb0 Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: error: updateQueue error: null Oct 31 16:44:39 volumio-vx86 volumio[909]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Oct 31 16:44:39 volumio-vx86 volumio[909]: info: QobuzConnect: QOBUZ Connect daemon connected Oct 31 16:44:39 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioStop Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreStateMachine::stop Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 16:44:39 volumio-vx86 volumio[909]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Starting Shairport Sync Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.131 [2743.2743] INFO SampleApp: Playback volume changed: 75 Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Preparing to generate the ALSA configuration file Oct 31 16:44:39 volumio-vx86 sudo[2774]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 16:44:39 volumio-vx86 sudo[2774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Asound.conf file unchanged, so no further update is needed Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Output device has changed, restarting MPD Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 31 16:44:39 volumio-vx86 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 16:44:39 volumio-vx86 systemd[1]: shairport-sync.service: Consumed 3.218s CPU time. Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Output device has changed, restarting Shairport Sync Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 16:44:39 volumio-vx86 sudo[2774]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:39 volumio-vx86 sudo[2777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 16:44:39 volumio-vx86 sudo[2777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:39 volumio-vx86 sudo[2777]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:39 volumio-vx86 sudo[2780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 16:44:39 volumio-vx86 sudo[2780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 16:44:39 volumio-vx86 volumio[909]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 31 16:44:39 volumio-vx86 volumio[909]: info: QobuzConnect: setDeactiveState invoked Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Preparing to generate the ALSA configuration file Oct 31 16:44:39 volumio-vx86 systemd[1]: mpd.service: Deactivated successfully. Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 31 16:44:39 volumio-vx86 systemd[1]: mpd.socket: Deactivated successfully. Oct 31 16:44:39 volumio-vx86 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 31 16:44:39 volumio-vx86 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 31 16:44:39 volumio-vx86 systemd[1]: Starting mpd.service - Music Player Daemon... Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Reading ALSA contributions from plugins. Oct 31 16:44:39 volumio-vx86 volumio[909]: info: MPD Permissions set Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Shairport-Sync Started Oct 31 16:44:39 volumio-vx86 sudo[2810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 sudo[2810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:39 volumio-vx86 sudo[2807]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 31 16:44:39 volumio-vx86 sudo[2807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 16:44:39 volumio-vx86 sudo[2807]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 31 16:44:39 volumio-vx86 sudo[2810]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Starting Shairport Sync Oct 31 16:44:39 volumio-vx86 sudo[2822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 31 16:44:39 volumio-vx86 sudo[2822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Asound.conf file written Oct 31 16:44:39 volumio-vx86 sudo[2824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 16:44:39 volumio-vx86 sudo[2824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 31 16:44:39 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:39.816 [2743.2743] INFO SampleApp: Stopping Local configuration server Oct 31 16:44:39 volumio-vx86 sudo[2828]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 31 16:44:39 volumio-vx86 sudo[2828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 31 16:44:39 volumio-vx86 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 31 16:44:39 volumio-vx86 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 16:44:39 volumio-vx86 sudo[2828]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:39 volumio-vx86 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 16:44:39 volumio-vx86 sudo[2824]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:39 volumio-vx86 volumio[909]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Output device has changed, restarting MPD Oct 31 16:44:39 volumio-vx86 volumio[909]: info: Output device has changed, restarting Shairport Sync Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:39 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:39 volumio-vx86 sudo[2846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 16:44:40 volumio-vx86 sudo[2846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:40 volumio-vx86 sudo[2853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 16:44:40 volumio-vx86 sudo[2846]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:40 volumio-vx86 volumio[909]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 16:44:40 volumio-vx86 volumiobt[2859]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Oct 31 16:44:40 volumio-vx86 volumio[909]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 sudo[2853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:40 volumio-vx86 volumiobt[2860]: [83B blob data] Oct 31 16:44:40 volumio-vx86 volumiobt[2860]: No default controller available Oct 31 16:44:40 volumio-vx86 volumiobt[2860]: [bluetoothctl]> pairable on Oct 31 16:44:40 volumio-vx86 volumiobt[2860]: No default controller available Oct 31 16:44:40 volumio-vx86 volumio[909]: info: QobuzConnect: setDeactiveState invoked Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:40 volumio-vx86 volumiobt[2860]: [bluetoothctl]> Oct 31 16:44:40 volumio-vx86 volumiobt[2864]: INFO [BTSTART] Registering Bluetooth agent... Oct 31 16:44:40 volumio-vx86 volumiobt[2869]: No agent is registered Oct 31 16:44:40 volumio-vx86 systemd[1]: mpd.service: Deactivated successfully. Oct 31 16:44:40 volumio-vx86 systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 31 16:44:40 volumio-vx86 systemd[1]: mpd.socket: Deactivated successfully. Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:40 volumio-vx86 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 31 16:44:40 volumio-vx86 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 31 16:44:40 volumio-vx86 volumiobt[2872]: INFO [BTSTART] Agent registered successfully. Oct 31 16:44:40 volumio-vx86 volumiobt[2874]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Oct 31 16:44:40 volumio-vx86 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 31 16:44:40 volumio-vx86 systemd[1]: Starting mpd.service - Music Player Daemon... Oct 31 16:44:40 volumio-vx86 volumio[909]: info: MPD Permissions set Oct 31 16:44:40 volumio-vx86 volumio[909]: info: Shairport-Sync Started Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 sudo[2876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 sudo[2876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 31 16:44:40 volumio-vx86 sudo[2875]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 31 16:44:40 volumio-vx86 sudo[2875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 16:44:40 volumio-vx86 sudo[2876]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:40 volumio-vx86 sudo[2875]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:40 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 16:44:40 volumio-vx86 volumio[909]: info: Starting Shairport Sync Oct 31 16:44:40 volumio-vx86 sudo[2887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 31 16:44:40 volumio-vx86 sudo[2887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:40 volumio-vx86 sudo[2891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 16:44:40 volumio-vx86 sudo[2891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:40 volumio-vx86 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 31 16:44:40 volumio-vx86 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 31 16:44:40 volumio-vx86 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 16:44:40 volumio-vx86 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 16:44:40 volumio-vx86 sudo[2891]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:40 volumio-vx86 volumio[909]: info: Shairport-Sync Started Oct 31 16:44:40 volumio-vx86 sudo[2911]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 16:44:40 volumio-vx86 sudo[2912]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 31 16:44:40 volumio-vx86 sudo[2911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:40 volumio-vx86 sudo[2912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:41 volumio-vx86 sudo[2912]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:41 volumio-vx86 sudo[2911]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:41 volumio-vx86 qobuz-connect[2743]: 20251031 16:44:41.074 [2743.2743] INFO SampleApp: shat down connection on UNIX socket Oct 31 16:44:41 volumio-vx86 systemd[1]: qobuz-connect.service: Deactivated successfully. Oct 31 16:44:41 volumio-vx86 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Oct 31 16:44:41 volumio-vx86 volumio[909]: verbose: New Socket.io Connection to 192.168.1.100 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:144.0) Gecko/20100101 Firefox/144.0 Engine version: 3 Transport: polling Total Clients: 12 Oct 31 16:44:41 volumio-vx86 volumio[909]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Oct 31 16:44:41 volumio-vx86 volumio[909]: info: QobuzConnect: setDeactiveState invoked Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 31 16:44:41 volumio-vx86 sudo[2887]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:41 volumio-vx86 sudo[2822]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Executing endpoint qc_getconfig Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.324 [2918.2918] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.325 [2918.2918] INFO VolumeManager: [0x55e90e1abb30]: Setting new playback volume: 75 Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.325 [2918.2918] INFO VolumeManager: [0x55e90e1abb30]: Setting new mute state: 0 Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.325 [2918.2918] INFO QobuzConnect: [0x55e90e1acd50]: Client initialized! Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.325 [2918.2918] INFO SampleApp: Starting Avahi advertising, name: Volumio-vx86, service name: _qobuz-connect._tcp Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.348 [2918.2918] INFO LocalConfigManager: [0x55e90e1aae20]: Starting Local Configuration server Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.348 [2918.2918] INFO SampleApp: Starting Local configuration server Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.348 [2918.2918] INFO SampleApp: Connected to UNIX socket client 0x55e90e181bb0 Oct 31 16:44:41 volumio-vx86 volumio[909]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Oct 31 16:44:41 volumio-vx86 volumio[909]: info: QobuzConnect: QOBUZ Connect daemon connected Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Received Get System Info Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Discovery: Getting this device information Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetVisibleSources Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumiobt[2877]: INFO:a2dp-agent:Connecting to system bus. Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Received Get System Info Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Discovery: Getting this device information Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Listing playlists Oct 31 16:44:41 volumio-vx86 qobuz-connect[2918]: 20251031 16:44:41.474 [2918.2918] INFO SampleApp: Playback volume changed: 75 Oct 31 16:44:41 volumio-vx86 volumiobt[2877]: ERROR:a2dp-agent:No Bluetooth adapter found: Bluetooth adapter not found Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Received Get System Info Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 16:44:41 volumio-vx86 volumio[909]: info: Discovery: Getting this device information Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:41 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 31 16:44:41 volumio-vx86 volumiobt[2926]: INFO [BTSTART] Disconnecting all Bluetooth devices... Oct 31 16:44:41 volumio-vx86 volumio[909]: info: TidalConnect service stoped! Oct 31 16:44:41 volumio-vx86 volumiobt[2933]: INFO [BTSTART] Unregistering Bluetooth agent... Oct 31 16:44:41 volumio-vx86 volumiobt[2936]: No agent is registered Oct 31 16:44:41 volumio-vx86 volumiobt[2939]: INFO [BTSTART] Stopping bluealsa-aplay (if any)... Oct 31 16:44:41 volumio-vx86 volumiobt[2942]: INFO [BTSTART] Stopping A2DP agent (a2dp-agent)... Oct 31 16:44:41 volumio-vx86 sudo[2938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 31 16:44:41 volumio-vx86 sudo[2938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:42 volumio-vx86 mpd[2889]: 2025-10-31T16:44:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 31 16:44:42 volumio-vx86 systemd[1]: Started mpd.service - Music Player Daemon. Oct 31 16:44:42 volumio-vx86 systemd[1]: volumiobt.service: Deactivated successfully. Oct 31 16:44:42 volumio-vx86 sudo[2780]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:42 volumio-vx86 sudo[2853]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:42 volumio-vx86 systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 31 16:44:42 volumio-vx86 systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 31 16:44:42 volumio-vx86 systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 31 16:44:42 volumio-vx86 systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 31 16:44:42 volumio-vx86 mpd_monitor.sh[2950]: MPD Monitor Service: Starting MPD Monitor Service Oct 31 16:44:42 volumio-vx86 sudo[2938]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:42 volumio-vx86 volumio[909]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 31 16:44:42 volumio-vx86 volumio[909]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: Successfully started MPD Monitor Oct 31 16:44:42 volumio-vx86 volumio[909]: error: MPD error: The expression evaluated to a falsy value: Oct 31 16:44:42 volumio-vx86 volumio[909]: assert.ok(self.idling) Oct 31 16:44:42 volumio-vx86 volumio[909]: error: The expression evaluated to a falsy value: Oct 31 16:44:42 volumio-vx86 volumio[909]: assert.ok(self.idling) Oct 31 16:44:42 volumio-vx86 volumio[909]: error: updateQueue error: null Oct 31 16:44:42 volumio-vx86 sudo[2956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 31 16:44:42 volumio-vx86 sudo[2956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:42 volumio-vx86 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Oct 31 16:44:42 volumio-vx86 sudo[2956]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:42 volumio-vx86 volumio[909]: info: Executing endpoint tc_getconfig Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 31 16:44:42 volumio-vx86 vtcs[2959]: STARTING TidalConnect services, version: 1.5.1-beta1 Oct 31 16:44:42 volumio-vx86 vtcs[2959]: STARTED TidalConnect services. Oct 31 16:44:42 volumio-vx86 volumio[909]: info: Executing endpoint tc_connect Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 31 16:44:42 volumio-vx86 volumio[909]: info: Connecting to TidalConnect Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::servicePushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::pushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioPushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output update for this device Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CorePlayQueue::getTrack 0 Oct 31 16:44:42 volumio-vx86 volumio[909]: 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} Oct 31 16:44:42 volumio-vx86 volumio[909]: verbose: CURRENT POSITION 0 Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::syncState stateService stop Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::syncState currentStatus stop Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::pushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioPushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output update for this device Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: No code Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::pushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioPushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output update for this device Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::servicePushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::pushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioPushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output update for this device Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CorePlayQueue::getTrack 0 Oct 31 16:44:42 volumio-vx86 volumio[909]: 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} Oct 31 16:44:42 volumio-vx86 volumio[909]: verbose: CURRENT POSITION 0 Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::syncState stateService stop Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::syncState currentStatus stop Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::pushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioPushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output update for this device Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: No code Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreStateMachine::pushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioPushState Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output update for this device Oct 31 16:44:42 volumio-vx86 volumio[909]: info: MRS: Pushing multiroomSync output Oct 31 16:44:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::volumioGetState Oct 31 16:44:42 volumio-vx86 volumio[909]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.zcS534SKWOZ8js11sSWRhNqpwU63.a9aeef0f8b3e2385eb65ecf2837d2e56.state.status' Oct 31 16:44:42 volumio-vx86 volumio[909]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.zcS534SKWOZ8js11sSWRhNqpwU63.a9aeef0f8b3e2385eb65ecf2837d2e56.state.status' Oct 31 16:44:42 volumio-vx86 volumio[909]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.zcS534SKWOZ8js11sSWRhNqpwU63.a9aeef0f8b3e2385eb65ecf2837d2e56.state.status' Oct 31 16:44:42 volumio-vx86 volumio[909]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.zcS534SKWOZ8js11sSWRhNqpwU63.a9aeef0f8b3e2385eb65ecf2837d2e56.state.status' Oct 31 16:44:44 volumio-vx86 volumio[909]: info: Executing endpoint metavolumio Oct 31 16:44:44 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 16:44:44 volumio-vx86 volumio[909]: info: Executing endpoint metavolumio Oct 31 16:44:44 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 16:44:45 volumio-vx86 sudo[2980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 31 16:44:45 volumio-vx86 sudo[2980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:45 volumio-vx86 systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 31 16:44:45 volumio-vx86 systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 31 16:44:45 volumio-vx86 systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 31 16:44:45 volumio-vx86 systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 31 16:44:45 volumio-vx86 mpd_monitor.sh[2983]: MPD Monitor Service: Starting MPD Monitor Service Oct 31 16:44:45 volumio-vx86 sudo[2980]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:45 volumio-vx86 volumio[909]: info: Successfully started MPD Monitor Oct 31 16:44:45 volumio-vx86 sudo[2985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 31 16:44:45 volumio-vx86 sudo[2985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:45 volumio-vx86 systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 31 16:44:45 volumio-vx86 systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 31 16:44:45 volumio-vx86 systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 31 16:44:45 volumio-vx86 systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 31 16:44:45 volumio-vx86 mpd_monitor.sh[2990]: MPD Monitor Service: Starting MPD Monitor Service Oct 31 16:44:45 volumio-vx86 sudo[2985]: pam_unix(sudo:session): session closed for user root Oct 31 16:44:45 volumio-vx86 volumio[909]: info: Successfully started MPD Monitor Oct 31 16:44:45 volumio-vx86 volumio[909]: info: TidalConnect service started! Oct 31 16:44:47 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 31 16:44:47 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 31 16:44:51 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 31 16:44:53 volumio-vx86 volumio[909]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/Systeminfo/volumio/bookworm/amd64 Oct 31 16:44:55 volumio-vx86 volumio[909]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/Systeminfo/volumio/bookworm/amd64 Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Folder /tmp/plugins removed Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Check plugin dependencies Oct 31 16:44:55 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Checking if plugin already exists Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Rename folder Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Folder /tmp/downloaded_plugin.zip removed Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Move to category Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Checking if install.sh is present Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Executing install.sh Oct 31 16:44:55 volumio-vx86 sudo[3034]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/Systeminfo/install.sh Oct 31 16:44:55 volumio-vx86 sudo[3034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Installing systeminfo Oct 31 16:44:55 volumio-vx86 sudo[3036]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt update Oct 31 16:44:55 volumio-vx86 sudo[3036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Get:1 http://deb.debian.org/debian bookworm InRelease [151 kB] Oct 31 16:44:55 volumio-vx86 volumio[909]: info: Get:2 https://deb.nodesource.com/node_20.x bookworm InRelease [4586 B] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:3 http://deb.debian.org/debian bookworm/main i386 Packages [8684 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:4 http://deb.debian.org/debian bookworm/main amd64 Packages [8791 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:5 http://deb.debian.org/debian bookworm/main Translation-en [6109 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:6 http://deb.debian.org/debian bookworm/contrib i386 Packages [46.0 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:7 http://deb.debian.org/debian bookworm/contrib amd64 Packages [53.5 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:8 http://deb.debian.org/debian bookworm/contrib Translation-en [48.4 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:9 http://deb.debian.org/debian bookworm/non-free amd64 Packages [102 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:10 http://deb.debian.org/debian bookworm/non-free i386 Packages [73.5 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:11 http://deb.debian.org/debian bookworm/non-free Translation-en [68.1 kB] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:12 http://deb.debian.org/debian bookworm/non-free-firmware i386 Packages [5904 B] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:13 http://deb.debian.org/debian bookworm/non-free-firmware amd64 Packages [6368 B] Oct 31 16:44:56 volumio-vx86 volumio[909]: info: Get:14 http://deb.debian.org/debian bookworm/non-free-firmware Translation-en [20.9 kB] Oct 31 16:44:57 volumio-vx86 volumio[909]: info: Get:15 https://deb.nodesource.com/node_20.x bookworm/main amd64 Packages [775 B] Oct 31 16:45:00 volumio-vx86 volumio[909]: info: Fetched 24.2 MB in 5s (5180 kB/s) Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Reading package lists... Oct 31 16:45:03 volumio-vx86 sudo[3036]: pam_unix(sudo:session): session closed for user root Oct 31 16:45:03 volumio-vx86 sudo[3268]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt install -y sysbench Oct 31 16:45:03 volumio-vx86 sudo[3268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Reading package lists... Oct 31 16:45:03 volumio-vx86 sudo[3268]: pam_unix(sudo:session): session closed for user root Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Configuration file doesn't exist, nothing to do Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Detected cpu architecture as x86_64 Oct 31 16:45:03 volumio-vx86 sudo[3277]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/user_interface/Systeminfo/c/hw_params_amd64 /data/plugins/user_interface/Systeminfo/hw_params Oct 31 16:45:03 volumio-vx86 sudo[3277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 16:45:03 volumio-vx86 sudo[3277]: pam_unix(sudo:session): session closed for user root Oct 31 16:45:03 volumio-vx86 sudo[3279]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chmod +x /data/plugins/user_interface/Systeminfo/hw_params Oct 31 16:45:03 volumio-vx86 sudo[3279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 16:45:03 volumio-vx86 sudo[3279]: pam_unix(sudo:session): session closed for user root Oct 31 16:45:03 volumio-vx86 volumio[909]: Plugin install end detected on script Oct 31 16:45:03 volumio-vx86 sudo[3034]: pam_unix(sudo:session): session closed for user root Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Install script completed Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Adding reference to registry Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Done installing plugin. Oct 31 16:45:03 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 31 16:45:03 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Folder /tmp/plugins removed Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Folder /tmp/downloaded_plugin.zip removed Oct 31 16:45:03 volumio-vx86 volumio[909]: info: Folder /data/temp removed Oct 31 16:45:06 volumio-vx86 volumio[909]: info: Enabling plugin Systeminfo Oct 31 16:45:06 volumio-vx86 volumio[909]: info: Loading plugin "Systeminfo"... Oct 31 16:45:06 volumio-vx86 volumio[909]: error: Could not copy default configuration to /data/configuration/user_interface/Systeminfo/config.json Oct 31 16:45:06 volumio-vx86 volumio[909]: Error reading configuration. Defaulting to empty configuration Oct 31 16:45:06 volumio-vx86 volumio[909]: info: PLUGIN START: Systeminfo Oct 31 16:45:06 volumio-vx86 volumio[909]: info: Done. Oct 31 16:45:12 volumio-vx86 volumio[909]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 31 16:45:13 volumio-vx86 volumio[909]: info: CALLMETHOD: user_interface Systeminfo getsysteminfo undefined Oct 31 16:45:13 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: Systeminfo , getsysteminfo Oct 31 16:45:13 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 16:45:14 volumio-vx86 dbus-daemon[566]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.52' (uid=1000 pid=3341 comm="hostnamectl --json short") Oct 31 16:45:14 volumio-vx86 systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Oct 31 16:45:14 volumio-vx86 dbus-daemon[566]: [system] Successfully activated service 'org.freedesktop.hostname1' Oct 31 16:45:14 volumio-vx86 systemd[1]: Started systemd-hostnamed.service - Hostname Service. Oct 31 16:45:14 volumio-vx86 dbus-daemon[566]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.53' (uid=0 pid=3342 comm="/lib/systemd/systemd-hostnamed") Oct 31 16:45:14 volumio-vx86 systemd[1]: Starting polkit.service - Authorization Manager... Oct 31 16:45:14 volumio-vx86 polkitd[3344]: Started polkitd version 122 Oct 31 16:45:14 volumio-vx86 polkitd[3344]: Loading rules from directory /etc/polkit-1/rules.d Oct 31 16:45:14 volumio-vx86 polkitd[3344]: Loading rules from directory /usr/share/polkit-1/rules.d Oct 31 16:45:14 volumio-vx86 polkitd[3344]: Finished loading, compiling and executing 2 rules Oct 31 16:45:14 volumio-vx86 dbus-daemon[566]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Oct 31 16:45:14 volumio-vx86 systemd[1]: Started polkit.service - Authorization Manager. Oct 31 16:45:14 volumio-vx86 polkitd[3344]: Acquired the name org.freedesktop.PolicyKit1 on the system bus Oct 31 16:45:14 volumio-vx86 dbus-daemon[566]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.53" (uid=0 pid=3342 comm="/lib/systemd/systemd-hostnamed") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.InteractiveAuthorizationRequired" requested_reply="0" destination=":1.52" (uid=1000 pid=3341 comm="hostnamectl --json short") Oct 31 16:45:15 volumio-vx86 volumio[909]: info: Firmware detection outer try failed: Board model detection failed: Command failed: cat /proc/device-tree/model Oct 31 16:45:15 volumio-vx86 volumio[909]: cat: /proc/device-tree/model: No such file or directory Oct 31 16:45:18 volumio-vx86 volumio[909]: error: Audio hardware detection failed, check if "hw_params" exists and is executable: Oct 31 16:45:18 volumio-vx86 sudo[3906]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 31 16:45:18 volumio-vx86 sudo[3906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 16:45:18 volumio-vx86 sudo[3906]: pam_unix(sudo:session): session closed for user root Oct 31 16:45:42 volumio-vx86 volumio[909]: info: CoreCommandRouter::Close All Modals sent Oct 31 16:45:44 volumio-vx86 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Oct 31 16:45:45 volumio-vx86 volumio[909]: info: CALLMETHOD: user_interface Systeminfo runBench undefined Oct 31 16:45:45 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: Systeminfo , runBench Oct 31 16:45:46 volumio-vx86 volumio[909]: info: CALLMETHOD: user_interface Systeminfo runSysbench undefined Oct 31 16:45:47 volumio-vx86 volumio[909]: info: CoreCommandRouter::executeOnPlugin: Systeminfo , runSysbench Oct 31 16:45:47 volumio-vx86 volumio[909]: info: Starting full sysbench sequence... Oct 31 16:45:47 volumio-vx86 volumio[909]: error: Sysbench failed: Command failed: sysbench cpu --threads=$(nproc) --time=10 run Oct 31 16:45:47 volumio-vx86 volumio[909]: /bin/sh: 1: sysbench: not found Oct 31 16:45:47 volumio-vx86 volumio[909]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 16:45:47 volumio-vx86 volumio[909]: Error: Command failed: sysbench cpu --threads=$(nproc) --time=10 run Oct 31 16:45:47 volumio-vx86 volumio[909]: /bin/sh: 1: sysbench: not found Oct 31 16:45:47 volumio-vx86 volumio[909]: at ChildProcess.exithandler (node:child_process:421:12) Oct 31 16:45:47 volumio-vx86 volumio[909]: at ChildProcess.emit (node:events:514:28) Oct 31 16:45:47 volumio-vx86 volumio[909]: at maybeClose (node:internal/child_process:1105:16) Oct 31 16:45:47 volumio-vx86 volumio[909]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) { Oct 31 16:45:47 volumio-vx86 volumio[909]: code: 127, Oct 31 16:45:47 volumio-vx86 volumio[909]: killed: false, Oct 31 16:45:47 volumio-vx86 volumio[909]: signal: null, Oct 31 16:45:47 volumio-vx86 volumio[909]: cmd: 'sysbench cpu --threads=$(nproc) --time=10 run' Oct 31 16:45:47 volumio-vx86 volumio[909]: } Oct 31 16:45:47 volumio-vx86 volumio[909]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 16:45:47 volumio-vx86 sudo[4008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-31 16:44' Oct 31 16:45:47 volumio-vx86 sudo[4008]: 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="5ef3d56f987d109f3e21bfa246dbbb723cf6a917" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="b5a4a000e056eaff366fbb6591bf2240b12246d0" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Oct 28 12:58:27 UTC 2025" VOLUMIO_VERSION="4.063" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="1ea1dcf1aeec92ef400ab65816c1569c"