Apr 11 00:29:00 volumio volumio[1790]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 00:29:00 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 00:29:00 volumio volumio[1790]: info: Streaming services startup Apr 11 00:29:00 volumio volumio[1790]: info: Starting Streaming Daemon Apr 11 00:29:00 volumio volumio[1790]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 00:29:00 volumio sudo[2098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 00:29:00 volumio sudo[2098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:00 volumio sudo[2098]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:00 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 00:29:00 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:00 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 00:29:00 volumio volumio[1790]: error: Cannot start Volumio Streaming Daemon Apr 11 00:29:00 volumio volumio[1790]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 00:29:00 volumio volumio[1790]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 00:29:01 volumio volumio[1790]: verbose: New Socket.io Connection to 192.168.2.213 from 192.168.2.245 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:149.0) Gecko/20100101 Firefox/149.0 Engine version: 3 Transport: polling Total Clients: 10 Apr 11 00:29:01 volumio volumio[1790]: verbose: New Socket.io Connection to 192.168.2.213 from 192.168.2.245 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:149.0) Gecko/20100101 Firefox/149.0 Engine version: 3 Transport: polling Total Clients: 11 Apr 11 00:29:01 volumio volumio[1790]: verbose: New Socket.io Connection to 192.168.2.213 from 192.168.2.245 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:149.0) Gecko/20100101 Firefox/149.0 Engine version: 3 Transport: polling Total Clients: 12 Apr 11 00:29:02 volumio volumio-remote-updater[701]: Test mode disabled Apr 11 00:29:02 volumio volumio-remote-updater[701]: Alpha mode disabled Apr 11 00:29:02 volumio volumio-remote-updater[701]: Alpha legacy test mode disabled Apr 11 00:29:02 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 11 00:29:03 volumio volumio[1790]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 00:29:03 volumio volumio[1790]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 11 00:29:03 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 11 00:29:04 volumio volumio[1790]: verbose: New Socket.io Connection to 192.168.2.213 from 192.168.2.245 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:149.0) Gecko/20100101 Firefox/149.0 Engine version: 3 Transport: polling Total Clients: 13 Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:04 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:04 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 00:29:04 volumio volumio[1790]: info: Received Get System Info Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 00:29:04 volumio volumio[1790]: info: Discovery: Getting this device information Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:04 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:04 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:04 volumio volumio[1790]: info: Listing playlists Apr 11 00:29:04 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 11 00:29:04 volumio volumio[1790]: info: MyVolumio token set successfully Apr 11 00:29:04 volumio volumio[1790]: info: MYVOLUMIO: Adding device Apr 11 00:29:04 volumio volumio[1790]: info: MYVOLUMIO: Evaluating Server Apr 11 00:29:05 volumio volumio[1790]: info: MyVolumio Plan changed: premium Apr 11 00:29:05 volumio volumio[1790]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 11 00:29:05 volumio volumio[1790]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 00:29:05 volumio volumio[1790]: info: Removing audio output: Apr 11 00:29:05 volumio volumio[1790]: info: MYVOLUMIO: Adding device Apr 11 00:29:05 volumio volumio[1790]: info: MYVOLUMIO: Evaluating Server Apr 11 00:29:07 volumio volumio[1790]: info: Setting Geolocation for MyVolumio to us2 Apr 11 00:29:07 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:07 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:07 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:07 volumio volumio[1790]: info: Setting Geolocation for MyVolumio to us2 Apr 11 00:29:07 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:07 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:07 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:07 volumio volumio[1790]: info: Remote config written successfully Apr 11 00:29:07 volumio volumio[1790]: info: Starting Tunnel 1 Apr 11 00:29:07 volumio volumio[1790]: info: Starting Tunnel Connection Checker Apr 11 00:29:07 volumio volumio[1790]: info: Completed starting MyVolumio Plugin Apr 11 00:29:07 volumio volumio[1790]: info: MYVolumio Device enabled Apr 11 00:29:07 volumio volumio[1790]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 11 00:29:07 volumio volumio[1790]: info: MyVolumio status changed Apr 11 00:29:07 volumio volumio[1790]: info: Streaming services startup Apr 11 00:29:07 volumio volumio[1790]: info: Starting Streaming Daemon Apr 11 00:29:07 volumio sudo[2148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 00:29:07 volumio sudo[2148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:08 volumio volumio[1790]: info: Successfully Added MyVolumio device Apr 11 00:29:08 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 00:29:08 volumio sudo[2148]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:08 volumio volumio[1790]: error: Cannot start Volumio Streaming Daemon Apr 11 00:29:08 volumio volumio[1790]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 00:29:08 volumio volumio[1790]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 00:29:08 volumio volumio[1790]: info: Updating MyVolumio device info Apr 11 00:29:08 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:08 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:08 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:08 volumio volumio[1790]: info: Successfully Added MyVolumio device Apr 11 00:29:08 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 11 00:29:08 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 11 00:29:09 volumio volumio[1790]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 11 00:29:09 volumio volumio[1790]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 11 00:29:10 volumio volumio[1790]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Apr 11 00:29:10 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 11 00:29:19 volumio volumio[1790]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Apr 11 00:29:19 volumio sudo[2167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 11 00:29:19 volumio sudo[2167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:19 volumio sudo[2167]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:19 volumio volumio[1790]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Apr 11 00:29:19 volumio volumio[1790]: info: MRS: MultiRoom plugin initialized Apr 11 00:29:19 volumio volumio[1790]: info: MRS: STOPPING SNAPCLIENT Apr 11 00:29:19 volumio volumio[1790]: info: MRS: Snap server stop Apr 11 00:29:19 volumio volumio[1790]: info: MRS: STOPPING volumioStreaming Apr 11 00:29:20 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 11 00:29:20 volumio sudo[2184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 11 00:29:20 volumio sudo[2184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:20 volumio sudo[2186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 11 00:29:20 volumio sudo[2186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:20 volumio sudo[2188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 11 00:29:20 volumio sudo[2188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:20 volumio sudo[2190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 11 00:29:20 volumio sudo[2190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:20 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 11 00:29:20 volumio sudo[2190]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:20 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 11 00:29:20 volumio sudo[2186]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:20 volumio sudo[2184]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:20 volumio sudo[2188]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:20 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 11 00:29:20 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 11 00:29:20 volumio volumio[1790]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Apr 11 00:29:20 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 11 00:29:21 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 11 00:29:21 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 11 00:29:21 volumio volumio[1790]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Apr 11 00:29:21 volumio volumio[1790]: info: Preparing to generate the ALSA configuration file Apr 11 00:29:21 volumio volumio[1790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Apr 11 00:29:21 volumio volumio[1790]: info: Updating MyVolumio device info Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::volumioGetBrowseSources Apr 11 00:29:21 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 00:29:21 volumio volumio[1790]: info: Successfully Updated MyVolumio device Apr 11 00:29:21 volumio volumio[1790]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 11 00:29:21 volumio volumio[1790]: info: Reading ALSA contributions from plugins. Apr 11 00:29:22 volumio volumio[1790]: info: MRS: Removed streaming files Apr 11 00:29:22 volumio volumio[1790]: info: MRS: volumioStreaming STOPPED Apr 11 00:29:22 volumio volumio[1790]: info: MRS: SNAPSERVER STOPPED Apr 11 00:29:22 volumio volumio[1790]: info: MRS: SNAPCLIENT STOPPED Apr 11 00:29:24 volumio sudo[2220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 11 00:29:24 volumio sudo[2220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:24 volumio volumio[1790]: info: Successfully Updated MyVolumio device Apr 11 00:29:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 00:29:24 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 00:29:24 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 11 00:29:24 volumio sudo[2220]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:25 volumio autossh[2223]: port set to 0, monitoring disabled Apr 11 00:29:25 volumio autossh[2223]: starting ssh (count 1) Apr 11 00:29:25 volumio autossh[2223]: ssh child pid is 2226 Apr 11 00:29:25 volumio volumio[1790]: info: Remote SSH Started Apr 11 00:29:25 volumio volumiossh-tunnel[2226]: Warning: Permanently added '[us2.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 11 00:29:26 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:26 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:26 volumio volumio[1790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Apr 11 00:29:26 volumio volumio[1790]: info: Asound.conf file written Apr 11 00:29:26 volumio sudo[2230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 11 00:29:26 volumio sudo[2230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:26 volumio sudo[2230]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:27 volumio volumio[1790]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 11 00:29:27 volumio volumio[1790]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 11 00:29:27 volumio volumio[1790]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 11 00:29:27 volumio volumio[1790]: info: Output device has changed, restarting MPD Apr 11 00:29:27 volumio volumio[1790]: info: Output device has changed, restarting Shairport Sync Apr 11 00:29:27 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:27 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:27 volumio sudo[2236]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 00:29:27 volumio sudo[2236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:27 volumio volumio[1790]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 00:29:27 volumio volumio[1790]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 00:29:27 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:27 volumio sudo[2236]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:27 volumio sudo[2238]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 00:29:27 volumio sudo[2238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:27 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 11 00:29:27 volumio volumio[1790]: ------------------------------------ BT MESSAGE: [FUNC] onStart Apr 11 00:29:27 volumio volumio[1790]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Apr 11 00:29:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 00:29:27 volumio volumio[1790]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Apr 11 00:29:27 volumio volumio[1790]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Apr 11 00:29:27 volumio volumio[1790]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Apr 11 00:29:27 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 11 00:29:27 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 11 00:29:27 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 00:29:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 00:29:27 volumio systemd[1]: mpd.service: Consumed 3.617s CPU time. Apr 11 00:29:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 00:29:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 00:29:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 00:29:27 volumio volumio[1790]: info: MRS: Pushing multiroomSync output for this device Apr 11 00:29:27 volumio volumio[1790]: info: MRS: Pushing multiroomSync output Apr 11 00:29:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 00:29:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 00:29:27 volumio bluetoothd[905]: Path / reserved for Adv Monitor app :1.33 Apr 11 00:29:27 volumio bluetoothd[905]: Adv Monitor app :1.33 disconnected from D-Bus Apr 11 00:29:27 volumio volumio[1790]: info: Adding audio output: Apr 11 00:29:27 volumio volumio[1790]: info: Adding audio output: Apr 11 00:29:28 volumio sudo[2250]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 00:29:28 volumio sudo[2250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 00:29:28 volumio sudo[2250]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:28 volumio volumio[1790]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 00:29:28 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:28 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 11 00:29:28 volumio volumio[1790]: info: Adding METAVOLUMIO REST API Endpoints Apr 11 00:29:28 volumio volumio[1790]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 11 00:29:28 volumio volumio[1790]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 11 00:29:28 volumio volumio[1790]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 11 00:29:28 volumio volumio[1790]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 11 00:29:28 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 11 00:29:28 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 11 00:29:28 volumio volumio[1790]: info: Preparing CD Folders Apr 11 00:29:28 volumio volumio[1790]: info: Adding CD REST API Endpoints Apr 11 00:29:28 volumio volumio[1790]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 11 00:29:28 volumio volumio[1790]: info: Starting UDEV Watcher for CD Apr 11 00:29:28 volumio volumio[1790]: info: Detecting CD presence with UDEV Apr 11 00:29:28 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 11 00:29:31 volumio mpd[2253]: 2026-04-11T00:29:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 00:29:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 00:29:31 volumio sudo[2238]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:33 volumio volumio[1790]: warn: [cd-plugin] cdspeedctl: device or media not ready Apr 11 00:29:33 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 11 00:29:33 volumio volumio[1790]: info: Adding inputs REST Endpoints Apr 11 00:29:33 volumio volumio[1790]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 11 00:29:33 volumio volumio[1790]: info: Scanning Audio Inputs Apr 11 00:29:34 volumio volumio[1790]: info: Checking against Known Cards name Apr 11 00:29:34 volumio volumio[1790]: info: Adding Server instance for streaming Apr 11 00:29:34 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 11 00:29:34 volumio volumio[1790]: error: Hi Res Audio Failed Login: Missing Login Data Apr 11 00:29:34 volumio volumio[1790]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 11 00:29:34 volumio volumio[1790]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 11 00:29:34 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 11 00:29:34 volumio volumio[1790]: info: Refreshing TIDAL token Apr 11 00:29:34 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 11 00:29:34 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 11 00:29:34 volumio volumio[1790]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Apr 11 00:29:34 volumio volumio[1790]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Apr 11 00:29:34 volumio volumio[1790]: info: QobuzConnect: Starting Qobuz Connect socket and service Apr 11 00:29:34 volumio sudo[2279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 00:29:34 volumio sudo[2279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:34 volumio volumio[1790]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Apr 11 00:29:34 volumio volumio[1790]: info: Stopping AccessToken refresher cron for QOBUZ Apr 11 00:29:34 volumio sudo[2285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 00:29:34 volumio sudo[2285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:34 volumio sudo[2279]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:34 volumio volumio[1790]: info: AccessToken refresher cron started for QOBUZ Apr 11 00:29:34 volumio volumio[1790]: info: Adding QOBUZ REST API Endpoints Apr 11 00:29:34 volumio sudo[2285]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:34 volumio volumio[1790]: info: MRS: Getting audio outputs on start Apr 11 00:29:34 volumio volumio[1790]: info: MRS: Requesting all other devices output Apr 11 00:29:34 volumio sudo[2289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 00:29:34 volumio sudo[2289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:35 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 00:29:35 volumio sudo[2289]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:35 volumio volumio[1790]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Apr 11 00:29:35 volumio volumio[1790]: info: MPD Permissions set Apr 11 00:29:35 volumio sudo[2294]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 11 00:29:35 volumio sudo[2294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:35 volumio volumio[1790]: info: Executing endpoint qc_getconfig Apr 11 00:29:35 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 11 00:29:36 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 11 00:29:36 volumio volumiobt[2301]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 11 00:29:36 volumio sudo[2294]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:36 volumio sudo[2302]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 11 00:29:36 volumio sudo[2302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:36 volumio sudo[2302]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.179 [2292.2292] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio sudo[2304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 11 00:29:36 volumio sudo[2304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio sudo[2304]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:36 volumio volumiobt[2306]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.349 [2292.2292] INFO VolumeManager: [0x44dfd8]: Setting new playback volume: 75 Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.349 [2292.2292] INFO VolumeManager: [0x44dfd8]: Setting new mute state: 0 Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.349 [2292.2292] INFO AudioStreamManager: [0x44dd30]: Setting new audio download buffer size: 1048576 Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.349 [2292.2292] INFO QobuzConnect: [0x44e8a0]: Client initialized! Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.349 [2292.2292] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Apr 11 00:29:36 volumio bluetoothd[905]: Adv Monitor app :1.35 disconnected from D-Bus Apr 11 00:29:36 volumio volumiobt[2314]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.386 [2292.2292] INFO LocalConfigManager: [0x44da58]: Starting Local Configuration server Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.386 [2292.2292] INFO SampleApp: Starting Local configuration server Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.387 [2292.2292] INFO SampleApp: Connected to UNIX socket client 0x438818 Apr 11 00:29:36 volumio qobuz-connect[2292]: 20260411 00:29:36.387 [2292.2292] INFO SampleApp: Playback volume changed: 75 Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:36 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:36 volumio volumiobt[2315]: [176B blob data] Apr 11 00:29:36 volumio volumiobt[2315]: [157B blob data] Apr 11 00:29:36 volumio volumiobt[2315]: [157B blob data] Apr 11 00:29:36 volumio volumiobt[2315]: [157B blob data] Apr 11 00:29:36 volumio volumiobt[2315]: [113B blob data] Apr 11 00:29:36 volumio volumiobt[2315]: [bluetoothctl]> discoverable on Apr 11 00:29:36 volumio volumiobt[2315]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Apr 11 00:29:36 volumio volumiobt[2315]: [bluetoothctl]> pairable on Apr 11 00:29:36 volumio bluetoothd[905]: Path / reserved for Adv Monitor app :1.37 Apr 11 00:29:36 volumio volumio[1790]: error: updateQueue error: null Apr 11 00:29:36 volumio bluetoothd[905]: Adv Monitor app :1.37 disconnected from D-Bus Apr 11 00:29:36 volumio volumiobt[2315]: [bluetoothctl]> Apr 11 00:29:36 volumio volumiobt[2318]: INFO [BTSTART] Registering Bluetooth agent... Apr 11 00:29:36 volumio volumiobt[2319]: [NEW] Media /org/bluez/hci0 Apr 11 00:29:36 volumio volumiobt[2319]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 11 00:29:36 volumio volumiobt[2319]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 11 00:29:36 volumio volumiobt[2319]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Apr 11 00:29:36 volumio bluetoothd[905]: Adv Monitor app :1.38 disconnected from D-Bus Apr 11 00:29:36 volumio volumiobt[2320]: No agent is registered Apr 11 00:29:36 volumio volumiobt[2320]: [NEW] Media /org/bluez/hci0 Apr 11 00:29:36 volumio volumiobt[2320]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 11 00:29:36 volumio volumiobt[2320]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 11 00:29:36 volumio volumiobt[2320]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Apr 11 00:29:36 volumio bluetoothd[905]: Adv Monitor app :1.39 disconnected from D-Bus Apr 11 00:29:36 volumio volumiobt[2321]: INFO [BTSTART] Agent registered successfully. Apr 11 00:29:36 volumio volumiobt[2322]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 11 00:29:36 volumio volumio[1790]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 11 00:29:36 volumio volumio[1790]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 11 00:29:36 volumio volumio[1790]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Apr 11 00:29:36 volumio volumio[1790]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Apr 11 00:29:37 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:37 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:37 volumio volumio[1790]: info: Access Token successfully retrieved Apr 11 00:29:37 volumio volumio[1790]: info: Starting Shairport Sync Apr 11 00:29:37 volumio volumio[1790]: error: MyVolumio Plugins failed to start in a timely fashion Apr 11 00:29:37 volumio volumio[1790]: error: Plugin music_service tidal failed to complete 'onStart' in a timely fashion Apr 11 00:29:37 volumio volumio[1790]: error: Plugin music_service tidalconnect failed to complete 'onStart' in a timely fashion Apr 11 00:29:37 volumio volumio[1790]: [Metrics] CommandRouter: 83s 656.08ms Apr 11 00:29:37 volumio volumio[1790]: info: CoreCommandRouter::volumiosetStartupVolume Apr 11 00:29:37 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 00:29:37 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 00:29:37 volumio sudo[2325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 00:29:37 volumio sudo[2325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:37 volumio volumio[1790]: info: CoreCommandRouter::Close All Modals sent Apr 11 00:29:37 volumio volumio[1790]: info: CoreCommandRouter::Close All Modals sent Apr 11 00:29:37 volumio volumiobt[2323]: 2026-04-11 00:29:37 a2dp-agent [INFO] Connecting to system D-Bus Apr 11 00:29:37 volumio volumiobt[2323]: 2026-04-11 00:29:37 a2dp-agent [INFO] Connected to system D-Bus Apr 11 00:29:38 volumio volumiobt[2323]: 2026-04-11 00:29:38 bluezutils [INFO] Found adapter at: /org/bluez/hci0 Apr 11 00:29:38 volumio volumiobt[2323]: 2026-04-11 00:29:38 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0 Apr 11 00:29:38 volumio volumiobt[2323]: 2026-04-11 00:29:38 a2dp-agent [INFO] Set DiscoverableTimeout to infinite Apr 11 00:29:38 volumio volumiobt[2323]: 2026-04-11 00:29:38 a2dp-agent [INFO] Enabled Discoverable mode Apr 11 00:29:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 00:29:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 00:29:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 00:29:38 volumio systemd[1]: shairport-sync.service: Consumed 1.744s CPU time. Apr 11 00:29:38 volumio volumio[1790]: info: TidalConnect service stoped! Apr 11 00:29:38 volumio volumiobt[2323]: 2026-04-11 00:29:38 a2dp-agent [INFO] Agent registered at /local/a2dpagent Apr 11 00:29:38 volumio volumiobt[2323]: 2026-04-11 00:29:38 a2dp-agent [INFO] Agent set as default Apr 11 00:29:38 volumio volumiobt[2323]: 2026-04-11 00:29:38 a2dp-agent [INFO] A2DP agent running, waiting for connections... Apr 11 00:29:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 00:29:38 volumio sudo[2325]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:38 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:38 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:38 volumio volumio[1790]: info: Shairport-Sync Started Apr 11 00:29:38 volumio volumio[1790]: info: Successfully retrieved User Session From TIDAL Apr 11 00:29:39 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 11 00:29:39 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 00:29:39 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 11 00:29:39 volumio volumio[1790]: info: Successfully retrieved User Subscription From TIDAL Apr 11 00:29:39 volumio volumio[1790]: info: Adding TIDAL to Browse Sources Apr 11 00:29:39 volumio volumio[1790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 00:29:39 volumio volumio[1790]: info: [1775888979668] CoreMusicLibrary::Adding element TIDAL Apr 11 00:29:39 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 00:29:39 volumio volumio[1790]: Cannot find translation for source TIDAL Apr 11 00:29:39 volumio volumio[1790]: info: Adding TIDAL REST API Endpoints Apr 11 00:29:39 volumio volumio[1790]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 11 00:29:39 volumio volumio[1790]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 11 00:29:40 volumio sudo[2357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 11 00:29:40 volumio sudo[2357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 00:29:40 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 11 00:29:40 volumio sudo[2357]: pam_unix(sudo:session): session closed for user root Apr 11 00:29:40 volumio volumio[1790]: info: Executing endpoint tc_getconfig Apr 11 00:29:40 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 11 00:29:40 volumio vtcs[2360]: STARTING TidalConnect services, version: 1.6.1 Apr 11 00:29:40 volumio vtcs[2360]: STARTED TidalConnect services. Apr 11 00:29:40 volumio volumio[1790]: info: Executing endpoint tc_connect Apr 11 00:29:40 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 11 00:29:40 volumio volumio[1790]: info: Connecting to TidalConnect Apr 11 00:29:41 volumio volumio[1790]: info: CoreCommandRouter::servicePushState Apr 11 00:29:41 volumio volumio[1790]: info: CoreStateMachine::pushState Apr 11 00:29:41 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:41 volumio volumio[1790]: info: CoreCommandRouter::volumioPushState Apr 11 00:29:41 volumio volumio[1790]: info: MRS: Pushing multiroomSync output update for this device Apr 11 00:29:41 volumio volumio[1790]: info: MRS: Pushing multiroomSync output Apr 11 00:29:41 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:41 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:41 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:41 volumio volumio[1790]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 00:29:41 volumio volumio[1790]: info: CoreCommandRouter::servicePushState Apr 11 00:29:41 volumio volumio[1790]: info: CoreStateMachine::pushState Apr 11 00:29:41 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:41 volumio volumio[1790]: info: CoreCommandRouter::volumioPushState Apr 11 00:29:41 volumio volumio[1790]: info: MRS: Pushing multiroomSync output update for this device Apr 11 00:29:41 volumio volumio[1790]: info: MRS: Pushing multiroomSync output Apr 11 00:29:41 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:29:41 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:41 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:29:41 volumio volumio[1790]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 00:29:43 volumio volumio[1790]: info: TidalConnect service started! Apr 11 00:29:44 volumio volumio[1790]: info: BOOT COMPLETED Apr 11 00:29:58 volumio vtcs[2360]: [2026-04-11 00:29:58] [error] handle_transport_init received error: TLS handshake failed Apr 11 00:29:58 volumio vtcs[2360]: [2026-04-11 00:29:58] [info] asio async_shutdown error: asio.ssl:167772567 (shutdown while in init) Apr 11 00:29:58 volumio vtcs[2360]: [2026-04-11 00:29:58.843] [tisoc] [error] [WebsocketServerTls.cpp:104] Connection failed. Session State: 3, Error Code: 8, Message: TLS handshake failed Apr 11 00:29:59 volumio sshd[2408]: Accepted password for root from 192.168.2.245 port 62264 ssh2 Apr 11 00:29:59 volumio sshd[2408]: pam_unix(sshd:session): session opened for user root(uid=0) by (uid=0) Apr 11 00:29:59 volumio systemd[1]: Created slice user-0.slice - User Slice of UID 0. Apr 11 00:29:59 volumio systemd[1]: Starting user-runtime-dir@0.service - User Runtime Directory /run/user/0... Apr 11 00:29:59 volumio systemd-logind[695]: New session 4 of user root. Apr 11 00:29:59 volumio systemd[1]: Finished user-runtime-dir@0.service - User Runtime Directory /run/user/0. Apr 11 00:29:59 volumio systemd[1]: Starting user@0.service - User Manager for UID 0... Apr 11 00:30:00 volumio (systemd)[2411]: pam_unix(systemd-user:session): session opened for user root(uid=0) by (uid=0) Apr 11 00:30:00 volumio systemd[2411]: Queued start job for default target default.target. Apr 11 00:30:00 volumio systemd[2411]: Created slice app.slice - User Application Slice. Apr 11 00:30:00 volumio systemd[2411]: Reached target paths.target - Paths. Apr 11 00:30:00 volumio systemd[2411]: Reached target timers.target - Timers. Apr 11 00:30:00 volumio systemd[2411]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Apr 11 00:30:00 volumio systemd[2411]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Apr 11 00:30:00 volumio systemd[2411]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Apr 11 00:30:00 volumio systemd[2411]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Apr 11 00:30:00 volumio systemd[2411]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Apr 11 00:30:00 volumio systemd[2411]: Reached target sockets.target - Sockets. Apr 11 00:30:00 volumio systemd[2411]: Reached target basic.target - Basic System. Apr 11 00:30:00 volumio systemd[2411]: mpris-proxy.service - Bluetooth mpris proxy was skipped because of an unmet condition check (ConditionUser=!@system). Apr 11 00:30:00 volumio systemd[2411]: Reached target default.target - Main User Target. Apr 11 00:30:00 volumio systemd[2411]: Startup finished in 934ms. Apr 11 00:30:00 volumio systemd[1]: Started user@0.service - User Manager for UID 0. Apr 11 00:30:01 volumio systemd[1]: Started session-4.scope - Session 4 of User root. Apr 11 00:30:01 volumio sshd[2408]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 11 00:30:01 volumio sudo[2439]: root : TTY=pts/0 ; PWD=/root ; USER=root ; COMMAND=/usr/bin/systemctl status vtcs Apr 11 00:30:01 volumio sudo[2439]: pam_unix(sudo:session): session opened for user root(uid=0) by root(uid=0) Apr 11 00:30:01 volumio sudo[2439]: pam_unix(sudo:session): session closed for user root Apr 11 00:30:01 volumio sshd[2408]: Received disconnect from 192.168.2.245 port 62264:11: disconnected by user Apr 11 00:30:01 volumio sshd[2408]: Disconnected from user root 192.168.2.245 port 62264 Apr 11 00:30:01 volumio sshd[2408]: pam_unix(sshd:session): session closed for user root Apr 11 00:30:01 volumio systemd[1]: session-4.scope: Deactivated successfully. Apr 11 00:30:01 volumio systemd-logind[695]: Session 4 logged out. Waiting for processes to exit. Apr 11 00:30:01 volumio systemd-logind[695]: Removed session 4. Apr 11 00:30:11 volumio systemd[1]: Stopping user@0.service - User Manager for UID 0... Apr 11 00:30:11 volumio systemd[2411]: Activating special unit exit.target... Apr 11 00:30:11 volumio systemd[2411]: Stopped target default.target - Main User Target. Apr 11 00:30:11 volumio systemd[2411]: Stopped target basic.target - Basic System. Apr 11 00:30:11 volumio systemd[2411]: Stopped target paths.target - Paths. Apr 11 00:30:11 volumio systemd[2411]: Stopped target sockets.target - Sockets. Apr 11 00:30:11 volumio systemd[2411]: Stopped target timers.target - Timers. Apr 11 00:30:11 volumio systemd[2411]: Closed dirmngr.socket - GnuPG network certificate management daemon. Apr 11 00:30:11 volumio systemd[2411]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Apr 11 00:30:11 volumio systemd[2411]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Apr 11 00:30:11 volumio systemd[2411]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Apr 11 00:30:11 volumio systemd[2411]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Apr 11 00:30:11 volumio systemd[2411]: Removed slice app.slice - User Application Slice. Apr 11 00:30:11 volumio systemd[2411]: Reached target shutdown.target - Shutdown. Apr 11 00:30:11 volumio systemd[2411]: Finished systemd-exit.service - Exit the Session. Apr 11 00:30:11 volumio systemd[2411]: Reached target exit.target - Exit the Session. Apr 11 00:30:11 volumio systemd[1]: user@0.service: Deactivated successfully. Apr 11 00:30:11 volumio systemd[1]: Stopped user@0.service - User Manager for UID 0. Apr 11 00:30:12 volumio systemd[1]: Stopping user-runtime-dir@0.service - User Runtime Directory /run/user/0... Apr 11 00:30:12 volumio systemd[1]: run-user-0.mount: Deactivated successfully. Apr 11 00:30:12 volumio systemd[1]: user-runtime-dir@0.service: Deactivated successfully. Apr 11 00:30:12 volumio systemd[1]: Stopped user-runtime-dir@0.service - User Runtime Directory /run/user/0. Apr 11 00:30:12 volumio systemd[1]: Removed slice user-0.slice - User Slice of UID 0. Apr 11 00:30:12 volumio systemd[1]: user-0.slice: Consumed 1.241s CPU time. Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:30:14 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:30:14 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:30:14 volumio volumio[1790]: info: Currently active: tidal Apr 11 00:30:14 volumio volumio[1790]: info: Stopping currently active service Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioStop Apr 11 00:30:14 volumio volumio[1790]: info: CoreStateMachine::stop Apr 11 00:30:14 volumio volumio[1790]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 00:30:14 volumio volumio[1790]: info: TidalConnect Active Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:30:14 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:30:14 volumio volumio[1790]: info: Currently active: tidal Apr 11 00:30:14 volumio volumio[1790]: info: Setting Volatile state to tidalconnect Apr 11 00:30:14 volumio volumio[1790]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::servicePushState Apr 11 00:30:14 volumio volumio[1790]: info: CoreStateMachine::pushState Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioPushState Apr 11 00:30:14 volumio volumio[1790]: info: MRS: Pushing multiroomSync output update for this device Apr 11 00:30:14 volumio volumio[1790]: info: MRS: Pushing multiroomSync output Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:30:14 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:30:14 volumio volumio[1790]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::servicePushState Apr 11 00:30:14 volumio volumio[1790]: info: CoreStateMachine::pushState Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioPushState Apr 11 00:30:14 volumio volumio[1790]: info: MRS: Pushing multiroomSync output update for this device Apr 11 00:30:14 volumio volumio[1790]: info: MRS: Pushing multiroomSync output Apr 11 00:30:14 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:30:14 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:30:14 volumio volumio[1790]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 00:30:14 volumio volumio5-onboarding[1413]: time=2026-04-11T00:30:14.652-06:00 level=WARN msg="received unknown player status" component=volumio status="" Apr 11 00:30:14 volumio volumio5-onboarding[1413]: time=2026-04-11T00:30:14.656-06:00 level=WARN msg="received unknown player status" component=volumio status="" Apr 11 00:30:15 volumio volumio[1790]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.oihhYg2OHKZs5gHdaUdkRyhFpAv1.f82bc0124076728659511e0d43035f9b.state.status' Apr 11 00:30:15 volumio vtcs[2360]: [2026-04-11 00:30:15] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Apr 11 00:30:15 volumio vtcs[2360]: [2026-04-11 00:30:15] [info] asio async_shutdown error: asio.system:32 (Broken pipe) Apr 11 00:30:18 volumio volumio[1790]: info: Executing endpoint metavolumio Apr 11 00:30:18 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 00:30:26 volumio sshd[2495]: Accepted password for root from 192.168.2.245 port 62378 ssh2 Apr 11 00:30:26 volumio sshd[2495]: pam_unix(sshd:session): session opened for user root(uid=0) by (uid=0) Apr 11 00:30:26 volumio systemd[1]: Created slice user-0.slice - User Slice of UID 0. Apr 11 00:30:26 volumio systemd[1]: Starting user-runtime-dir@0.service - User Runtime Directory /run/user/0... Apr 11 00:30:26 volumio systemd-logind[695]: New session 6 of user root. Apr 11 00:30:26 volumio systemd[1]: Finished user-runtime-dir@0.service - User Runtime Directory /run/user/0. Apr 11 00:30:26 volumio systemd[1]: Starting user@0.service - User Manager for UID 0... Apr 11 00:30:26 volumio (systemd)[2499]: pam_unix(systemd-user:session): session opened for user root(uid=0) by (uid=0) Apr 11 00:30:27 volumio systemd[2499]: Queued start job for default target default.target. Apr 11 00:30:27 volumio systemd[2499]: Created slice app.slice - User Application Slice. Apr 11 00:30:27 volumio systemd[2499]: Reached target paths.target - Paths. Apr 11 00:30:27 volumio systemd[2499]: Reached target timers.target - Timers. Apr 11 00:30:27 volumio systemd[2499]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Apr 11 00:30:27 volumio systemd[2499]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Apr 11 00:30:27 volumio systemd[2499]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Apr 11 00:30:27 volumio systemd[2499]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Apr 11 00:30:27 volumio systemd[2499]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Apr 11 00:30:27 volumio systemd[2499]: Reached target sockets.target - Sockets. Apr 11 00:30:27 volumio systemd[2499]: Reached target basic.target - Basic System. Apr 11 00:30:27 volumio systemd[2499]: mpris-proxy.service - Bluetooth mpris proxy was skipped because of an unmet condition check (ConditionUser=!@system). Apr 11 00:30:27 volumio systemd[2499]: Reached target default.target - Main User Target. Apr 11 00:30:27 volumio systemd[2499]: Startup finished in 988ms. Apr 11 00:30:27 volumio systemd[1]: Started user@0.service - User Manager for UID 0. Apr 11 00:30:27 volumio systemd[1]: Started session-6.scope - Session 6 of User root. Apr 11 00:30:27 volumio sshd[2495]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 11 00:30:28 volumio sudo[2526]: root : TTY=pts/0 ; PWD=/root ; USER=root ; COMMAND=/usr/bin/systemctl show vtcs -p NRestarts Apr 11 00:30:28 volumio sudo[2526]: pam_unix(sudo:session): session opened for user root(uid=0) by root(uid=0) Apr 11 00:30:28 volumio sudo[2526]: pam_unix(sudo:session): session closed for user root Apr 11 00:30:28 volumio sshd[2495]: Received disconnect from 192.168.2.245 port 62378:11: disconnected by user Apr 11 00:30:28 volumio sshd[2495]: Disconnected from user root 192.168.2.245 port 62378 Apr 11 00:30:28 volumio sshd[2495]: pam_unix(sshd:session): session closed for user root Apr 11 00:30:28 volumio systemd[1]: session-6.scope: Deactivated successfully. Apr 11 00:30:28 volumio systemd-logind[695]: Session 6 logged out. Waiting for processes to exit. Apr 11 00:30:28 volumio systemd-logind[695]: Removed session 6. Apr 11 00:30:33 volumio volumio[1790]: info: Executing endpoint tc_connect Apr 11 00:30:33 volumio volumio[1790]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 11 00:30:33 volumio volumio[1790]: info: Connecting to TidalConnect Apr 11 00:30:33 volumio vtcs[2360]: [2026-04-11 00:30:33.196] [tisoc] [warning] [SpkconServer.cpp:452] same state:2 Apr 11 00:30:33 volumio volumio[1790]: info: CoreCommandRouter::servicePushState Apr 11 00:30:33 volumio volumio[1790]: info: CoreStateMachine::pushState Apr 11 00:30:33 volumio volumio[1790]: info: CoreCommandRouter::volumioPushState Apr 11 00:30:33 volumio volumio[1790]: info: MRS: Pushing multiroomSync output update for this device Apr 11 00:30:33 volumio volumio[1790]: info: MRS: Pushing multiroomSync output Apr 11 00:30:33 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:30:33 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:30:33 volumio volumio[1790]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 00:30:33 volumio volumio[1790]: info: CoreCommandRouter::servicePushState Apr 11 00:30:33 volumio volumio[1790]: info: CoreStateMachine::pushState Apr 11 00:30:33 volumio volumio[1790]: info: CoreCommandRouter::volumioPushState Apr 11 00:30:33 volumio volumio[1790]: info: MRS: Pushing multiroomSync output update for this device Apr 11 00:30:33 volumio volumio[1790]: info: MRS: Pushing multiroomSync output Apr 11 00:30:33 volumio volumio[1790]: info: CoreCommandRouter::volumioGetState Apr 11 00:30:33 volumio volumio[1790]: info: CorePlayQueue::getTrack 0 Apr 11 00:30:33 volumio volumio[1790]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 00:30:33 volumio volumio5-onboarding[1413]: time=2026-04-11T00:30:33.346-06:00 level=WARN msg="received unknown player status" component=volumio status="" Apr 11 00:30:33 volumio volumio5-onboarding[1413]: time=2026-04-11T00:30:33.370-06:00 level=WARN msg="received unknown player status" component=volumio status="" Apr 11 00:30:33 volumio volumio[1790]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 00:30:33 volumio volumio[1790]: Error: ENOENT: no such file or directory, unlink '/tmp/c6mg7zJEE3Lfovff6CcnrsZQ6bC0kNoUADNokVxPDoIPVh43EYNtzAyIPxeKtx4Zvha8xs2tvvkPTt3zSMq6subIoVMg2QyfyPjB' Apr 11 00:30:33 volumio volumio[1790]: at Object.unlinkSync (node:fs:1899:3) Apr 11 00:30:33 volumio volumio[1790]: at ControllerTidalconnect.deleteCertificate (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:11265) Apr 11 00:30:33 volumio volumio[1790]: at TidalConnectClient. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:2774) Apr 11 00:30:33 volumio volumio[1790]: at TidalConnectClient.emit (node:events:514:28) Apr 11 00:30:33 volumio volumio[1790]: at TidalConnectClient.parseData (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:44713) Apr 11 00:30:33 volumio volumio[1790]: at /myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41683 Apr 11 00:30:33 volumio volumio[1790]: at Array.forEach () Apr 11 00:30:33 volumio volumio[1790]: at Socket. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41561) Apr 11 00:30:33 volumio volumio[1790]: at Socket.emit (node:events:514:28) Apr 11 00:30:33 volumio volumio[1790]: at addChunk (node:internal/streams/readable:343:12) Apr 11 00:30:33 volumio volumio[1790]: at readableAddChunk (node:internal/streams/readable:316:9) Apr 11 00:30:33 volumio volumio[1790]: at Readable.push (node:internal/streams/readable:253:10) Apr 11 00:30:33 volumio volumio[1790]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) { Apr 11 00:30:33 volumio volumio[1790]: errno: -2, Apr 11 00:30:33 volumio volumio[1790]: syscall: 'unlink', Apr 11 00:30:33 volumio volumio[1790]: code: 'ENOENT', Apr 11 00:30:33 volumio volumio[1790]: path: '/tmp/c6mg7zJEE3Lfovff6CcnrsZQ6bC0kNoUADNokVxPDoIPVh43EYNtzAyIPxeKtx4Zvha8xs2tvvkPTt3zSMq6subIoVMg2QyfyPjB' Apr 11 00:30:33 volumio volumio[1790]: } Apr 11 00:30:33 volumio volumio[1790]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 00:30:37 volumio sudo[2558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 00:29' Apr 11 00:30:37 volumio sudo[2558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"