Oct 14 19:17:23 volumio ntpd[1192]: CLOCK: time stepped by 18831407.336057
Oct 14 19:17:23 volumio ntpd[1192]: CLOCK: time changed from 2026-03-10 to 2026-10-14
Oct 14 19:17:23 volumio ntpd[1192]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes
Oct 14 19:17:23 volumio volumio[1347]: info: Discovery: A device disappeared from network
Oct 14 19:17:23 volumio volumio[1347]: info: Discovery: Device volumio disappeared from network
Oct 14 19:17:23 volumio volumio[1347]: info: Discovery: A device disappeared from network
Oct 14 19:17:23 volumio volumio[1347]: info: Discovery: adding e941dccc-3622-41ba-9a4e-a16ff5b5aabc
Oct 14 19:17:23 volumio volumio[1347]: info: Discovery: Found device Volumio
Oct 14 19:17:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:23 volumio volumio[1347]: info: CorePlayQueue::getTrack 0
Oct 14 19:17:23 volumio volumio[1347]: info: Discovery: this is already registered, e941dccc-3622-41ba-9a4e-a16ff5b5aabc
Oct 14 19:17:23 volumio volumio[1347]: info: Discovery: Found device Volumio
Oct 14 19:17:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:23 volumio volumio[1347]: info: CorePlayQueue::getTrack 0
Oct 14 19:17:24 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1.
Oct 14 19:17:24 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service...
Oct 14 19:17:24 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems...
Oct 14 19:17:24 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats.
Oct 14 19:17:24 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Oct 14 19:17:24 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Oct 14 19:17:24 volumio systemd[1]: e2scrub_all.service: Deactivated successfully.
Oct 14 19:17:24 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems.
Oct 14 19:17:24 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully.
Oct 14 19:17:24 volumio upmpdcli[1791]: Could not open config: /tmp/upmpdcli.conf
Oct 14 19:17:24 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Oct 14 19:17:24 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Oct 14 19:17:24 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully.
Oct 14 19:17:24 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service.
Oct 14 19:17:24 volumio sudo[1800]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Oct 14 19:17:24 volumio sudo[1800]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:24 volumio sudo[1800]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:24 volumio sudo[1802]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Oct 14 19:17:24 volumio sudo[1802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:24 volumio sudo[1802]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:24 volumio sudo[1806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Oct 14 19:17:24 volumio sudo[1806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:24 volumio volumio[1347]: info: Volumio Network Manager: Network status updated: 1
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Oct 14 19:17:26 volumio volumio[1347]: info: Adding plugin bluetooth to MyMusic Plugins
Oct 14 19:17:26 volumio volumio[1347]: info: Adding plugin multiroom to MyMusic Plugins
Oct 14 19:17:26 volumio volumio[1347]: info: Adding plugin metavolumio to MyMusic Plugins
Oct 14 19:17:26 volumio volumio[1347]: info: Adding plugin cd_controller to MyMusic Plugins
Oct 14 19:17:26 volumio volumio[1347]: info: Adding plugin qobuzconnect to MyMusic Plugins
Oct 14 19:17:26 volumio volumio[1347]: info: Adding plugin smart_inputs to MyMusic Plugins
Oct 14 19:17:26 volumio volumio[1347]: info: Adding plugin tidalconnect to MyMusic Plugins
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Oct 14 19:17:26 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:26 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:26 volumio volumio[1347]: info: Starting MyVolumio Remote Streaming Endpoints
Oct 14 19:17:26 volumio volumio[1347]: info: MyVolumio login type: Token
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Oct 14 19:17:26 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Oct 14 19:17:27 volumio volumio[1347]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Oct 14 19:17:27 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Oct 14 19:17:27 volumio volumio[1347]: info: Streaming services startup
Oct 14 19:17:27 volumio volumio[1347]: info: Starting Streaming Daemon
Oct 14 19:17:27 volumio sudo[1824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Oct 14 19:17:27 volumio sudo[1824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:27 volumio volumio[1347]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Oct 14 19:17:27 volumio sudo[1824]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:27 volumio volumio[1347]: error: Cannot start Volumio Streaming Daemon
Oct 14 19:17:27 volumio volumio[1347]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Oct 14 19:17:27 volumio volumio[1347]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Oct 14 19:17:27 volumio volumio[1347]: error: MyVolumio Custom Token format not valid, refreshing it
Oct 14 19:17:27 volumio volumio[1347]: info: MyVolumio login type: Token
Oct 14 19:17:28 volumio volumio[1347]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Oct 14 19:17:28 volumio volumio[1347]: info: MyVolumio token set successfully
Oct 14 19:17:28 volumio volumio[1347]: info: MYVOLUMIO: Adding device
Oct 14 19:17:28 volumio volumio[1347]: info: MYVOLUMIO: Evaluating Server
Oct 14 19:17:28 volumio volumio[1347]: info: MyVolumio Plan changed: premium
Oct 14 19:17:28 volumio volumio[1347]: info: [MyVolumio PluginManager] Subscribed plan changed to premium
Oct 14 19:17:28 volumio volumio[1347]: info: Removing browser output: myVolumio user plan is not superstar
Oct 14 19:17:28 volumio volumio[1347]: info: Removing audio output:
Oct 14 19:17:28 volumio volumio[1347]: info: MYVOLUMIO: Adding device
Oct 14 19:17:28 volumio volumio[1347]: info: MYVOLUMIO: Evaluating Server
Oct 14 19:17:28 volumio volumio[1347]: info: Remote config written successfully
Oct 14 19:17:28 volumio volumio[1347]: info: Starting Tunnel 1
Oct 14 19:17:28 volumio volumio[1347]: info: Starting Tunnel Connection Checker
Oct 14 19:17:28 volumio volumio[1347]: info: Completed starting MyVolumio Plugin
Oct 14 19:17:29 volumio volumio[1347]: info: MYVolumio Device enabled
Oct 14 19:17:29 volumio volumio[1347]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins...
Oct 14 19:17:29 volumio volumio[1347]: info: MyVolumio status changed
Oct 14 19:17:29 volumio volumio[1347]: info: Streaming services startup
Oct 14 19:17:29 volumio volumio[1347]: info: Starting Streaming Daemon
Oct 14 19:17:29 volumio sudo[1870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Oct 14 19:17:29 volumio sudo[1870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Oct 14 19:17:29 volumio volumio[1347]: error: [MyVolumio PluginManager] Cache data is invalid!
Oct 14 19:17:29 volumio sudo[1870]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:29 volumio volumio[1347]: error: Cannot start Volumio Streaming Daemon
Oct 14 19:17:29 volumio volumio[1347]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Oct 14 19:17:29 volumio volumio[1347]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Oct 14 19:17:29 volumio volumio[1347]: info: Setting Geolocation for MyVolumio to eu12
Oct 14 19:17:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:29 volumio volumio[1347]: info: Setting Geolocation for MyVolumio to eu12
Oct 14 19:17:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:29 volumio volumio[1347]: info: Successfully Added MyVolumio device
Oct 14 19:17:30 volumio volumio[1347]: info: Successfully Added MyVolumio device
Oct 14 19:17:30 volumio volumio[1347]: info: Updating MyVolumio device info
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"...
Oct 14 19:17:30 volumio volumio[1347]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "multiroom"...
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom
Oct 14 19:17:30 volumio sudo[1874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom
Oct 14 19:17:30 volumio sudo[1874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:30 volumio sudo[1874]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: MultiRoom plugin initialized
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: STOPPING SNAPCLIENT
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: Snap server stop
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: STOPPING volumioStreaming
Oct 14 19:17:30 volumio sudo[1891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient
Oct 14 19:17:30 volumio sudo[1891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:30 volumio sudo[1896]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming
Oct 14 19:17:30 volumio sudo[1893]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver
Oct 14 19:17:30 volumio sudo[1896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:30 volumio sudo[1893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"...
Oct 14 19:17:30 volumio sudo[1900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/*
Oct 14 19:17:30 volumio sudo[1900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "manifestui"...
Oct 14 19:17:30 volumio sudo[1900]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"...
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"...
Oct 14 19:17:30 volumio sudo[1891]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"...
Oct 14 19:17:30 volumio sudo[1896]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:30 volumio sudo[1893]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "tidal"...
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "qobuz"...
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"...
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"...
Oct 14 19:17:30 volumio volumio[1347]: info: Preparing to generate the ALSA configuration file
Oct 14 19:17:30 volumio volumio[1347]: info: Updating MyVolumio device info
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Oct 14 19:17:30 volumio volumio[1347]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
Oct 14 19:17:30 volumio volumio[1347]: info: Reading ALSA contributions from plugins.
Oct 14 19:17:30 volumio volumio[1347]: info: Successfully Updated MyVolumio device
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: Removed streaming files
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: volumioStreaming STOPPED
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: SNAPSERVER STOPPED
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: SNAPCLIENT STOPPED
Oct 14 19:17:30 volumio volumio[1347]: info: Asound.conf file unchanged, so no further update is needed
Oct 14 19:17:30 volumio volumio[1347]: info: Output device has changed, restarting MPD
Oct 14 19:17:30 volumio volumio[1347]: info: Output device has changed, restarting Shairport Sync
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:30 volumio sudo[1903]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Oct 14 19:17:30 volumio sudo[1903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:30 volumio sudo[1905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Oct 14 19:17:30 volumio sudo[1905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:30 volumio sudo[1903]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:30 volumio volumio[1347]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Oct 14 19:17:30 volumio volumio[1347]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Oct 14 19:17:30 volumio volumio[1347]: ------------------------------------ BT MESSAGE: [FUNC] onStart
Oct 14 19:17:30 volumio volumio[1347]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service
Oct 14 19:17:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Oct 14 19:17:30 volumio volumio[1347]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp
Oct 14 19:17:30 volumio volumio[1347]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/
Oct 14 19:17:30 volumio volumio[1347]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready.
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Plugin multiroom disabled by user. Not starting
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Oct 14 19:17:30 volumio volumio[1347]: info: Adding METAVOLUMIO REST API Endpoints
Oct 14 19:17:30 volumio volumio[1347]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Oct 14 19:17:30 volumio volumio[1347]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Oct 14 19:17:30 volumio volumio[1347]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Oct 14 19:17:30 volumio volumio[1347]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Oct 14 19:17:30 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Oct 14 19:17:30 volumio volumio[1347]: info: Preparing CD Folders
Oct 14 19:17:30 volumio volumio[1347]: info: Adding CD REST API Endpoints
Oct 14 19:17:30 volumio volumio[1347]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller
Oct 14 19:17:30 volumio volumio[1347]: info: Starting UDEV Watcher for CD
Oct 14 19:17:30 volumio volumio[1347]: info: Detecting CD presence with UDEV
Oct 14 19:17:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices
Oct 14 19:17:30 volumio bluetoothd[988]: Path / reserved for Adv Monitor app :1.21
Oct 14 19:17:30 volumio bluetoothd[988]: Adv Monitor app :1.21 disconnected from D-Bus
Oct 14 19:17:31 volumio systemd[1]: mpd.service: Deactivated successfully.
Oct 14 19:17:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Oct 14 19:17:31 volumio systemd[1]: mpd.service: Consumed 1.294s CPU time.
Oct 14 19:17:31 volumio systemd[1]: mpd.socket: Deactivated successfully.
Oct 14 19:17:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Oct 14 19:17:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Oct 14 19:17:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Oct 14 19:17:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Oct 14 19:17:31 volumio sudo[1920]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Oct 14 19:17:31 volumio sudo[1920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Oct 14 19:17:31 volumio sudo[1920]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:31 volumio mpd[1922]: 2026-10-14T19:17:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Oct 14 19:17:31 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Oct 14 19:17:31 volumio sudo[1905]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:35 volumio volumio[1347]: warn: [cd-plugin] cdspeedctl: device or media not ready
Oct 14 19:17:35 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Oct 14 19:17:35 volumio volumio[1347]: info: Adding inputs REST Endpoints
Oct 14 19:17:35 volumio volumio[1347]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Oct 14 19:17:35 volumio volumio[1347]: info: Scanning Audio Inputs
Oct 14 19:17:35 volumio volumio[1347]: info: Checking against Known Cards name
Oct 14 19:17:35 volumio volumio[1347]: info: Adding Server instance for streaming
Oct 14 19:17:35 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Oct 14 19:17:35 volumio volumio[1347]: error: Hi Res Audio Failed Login: Missing Login Data
Oct 14 19:17:35 volumio volumio[1347]: info: Adding HIGHRESAUDIO REST API Endpoints
Oct 14 19:17:35 volumio volumio[1347]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Oct 14 19:17:35 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Oct 14 19:17:35 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Oct 14 19:17:35 volumio volumio[1347]: info: Refreshing QOBUZ token
Oct 14 19:17:35 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Oct 14 19:17:36 volumio volumio[1347]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Oct 14 19:17:36 volumio volumio[1347]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Oct 14 19:17:36 volumio sudo[1944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Oct 14 19:17:36 volumio sudo[1944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio volumio[1347]: info: QobuzConnect: Starting Qobuz Connect socket and service
Oct 14 19:17:36 volumio volumio[1347]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Oct 14 19:17:36 volumio volumio[1347]: info: Adding TIDAL REST API Endpoints
Oct 14 19:17:36 volumio sudo[1951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Oct 14 19:17:36 volumio sudo[1951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio volumio[1347]: info: Successfully Updated MyVolumio device
Oct 14 19:17:36 volumio volumio[1347]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Oct 14 19:17:36 volumio volumio[1347]: info: MPD Permissions set
Oct 14 19:17:36 volumio sudo[1944]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio sudo[1954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Oct 14 19:17:36 volumio sudo[1954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio sudo[1951]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio sudo[1958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Oct 14 19:17:36 volumio sudo[1958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:36 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module.
Oct 14 19:17:36 volumio volumiobt[1971]: INFO [BTSTART] Ensuring Bluetooth directory exists...
Oct 14 19:17:36 volumio volumio[1347]: error: updateQueue error: null
Oct 14 19:17:36 volumio volumio[1347]: info: Starting Shairport Sync
Oct 14 19:17:36 volumio sudo[1954]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio sudo[1972]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth
Oct 14 19:17:36 volumio sudo[1972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio sudo[1972]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Oct 14 19:17:36 volumio sudo[1958]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio sudo[1977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth
Oct 14 19:17:36 volumio sudo[1977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio sudo[1974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Oct 14 19:17:36 volumio sudo[1977]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio sudo[1974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio volumiobt[1980]: INFO [BTSTART] Powering on Bluetooth if needed...
Oct 14 19:17:36 volumio volumio[1347]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::volumioStop
Oct 14 19:17:36 volumio volumio[1347]: info: CoreStateMachine::stop
Oct 14 19:17:36 volumio volumio[1347]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 14 19:17:36 volumio volumio[1347]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart
Oct 14 19:17:36 volumio volumio[1347]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 14 19:17:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Oct 14 19:17:36 volumio bluetoothd[988]: Path / reserved for Adv Monitor app :1.22
Oct 14 19:17:36 volumio bluetoothd[988]: Adv Monitor app :1.22 disconnected from D-Bus
Oct 14 19:17:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Oct 14 19:17:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Oct 14 19:17:36 volumio volumiobt[1983]: INFO [BTSTART] Making Bluetooth discoverable and pairable...
Oct 14 19:17:36 volumio systemd[1]: shairport-sync.service: Consumed 1.493s CPU time.
Oct 14 19:17:36 volumio sudo[1987]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Oct 14 19:17:36 volumio sudo[1987]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:36 volumio volumiobt[1984]: [176B blob data]
Oct 14 19:17:36 volumio volumiobt[1984]: [157B blob data]
Oct 14 19:17:36 volumio volumiobt[1984]: [157B blob data]
Oct 14 19:17:36 volumio volumiobt[1984]: [157B blob data]
Oct 14 19:17:36 volumio volumiobt[1984]: [113B blob data]
Oct 14 19:17:36 volumio bluetoothd[988]: Path / reserved for Adv Monitor app :1.23
Oct 14 19:17:36 volumio volumiobt[1984]: [bluetoothctl]> discoverable on
Oct 14 19:17:36 volumio volumiobt[1984]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended
Oct 14 19:17:36 volumio volumiobt[1984]: [bluetoothctl]> pairable on
Oct 14 19:17:36 volumio bluetoothd[988]: Adv Monitor app :1.23 disconnected from D-Bus
Oct 14 19:17:36 volumio volumiobt[1984]: [bluetoothctl]>
Oct 14 19:17:36 volumio volumiobt[1989]: INFO [BTSTART] Registering Bluetooth agent...
Oct 14 19:17:36 volumio volumio[1347]: info: Executing endpoint qc_getconfig
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Oct 14 19:17:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Oct 14 19:17:36 volumio sudo[1974]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio volumiobt[1990]: [NEW] Media /org/bluez/hci0
Oct 14 19:17:36 volumio volumiobt[1990]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Oct 14 19:17:36 volumio volumiobt[1990]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Oct 14 19:17:36 volumio volumiobt[1990]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Oct 14 19:17:36 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.
Oct 14 19:17:36 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.
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.163 [1976.1976] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Oct 14 19:17:36 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Oct 14 19:17:36 volumio bluetoothd[988]: Adv Monitor app :1.24 disconnected from D-Bus
Oct 14 19:17:36 volumio sudo[1987]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:36 volumio volumiobt[2009]: No agent is registered
Oct 14 19:17:36 volumio volumiobt[2009]: [NEW] Media /org/bluez/hci0
Oct 14 19:17:36 volumio volumiobt[2009]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Oct 14 19:17:36 volumio volumiobt[2009]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Oct 14 19:17:36 volumio volumiobt[2009]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Oct 14 19:17:36 volumio bluetoothd[988]: Adv Monitor app :1.27 disconnected from D-Bus
Oct 14 19:17:36 volumio volumio[1347]: info: Shairport-Sync Started
Oct 14 19:17:36 volumio volumiobt[2013]: INFO [BTSTART] Agent registered successfully.
Oct 14 19:17:36 volumio volumio[1347]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Oct 14 19:17:36 volumio volumio[1347]: info: QobuzConnect: QOBUZ Connect daemon connected
Oct 14 19:17:36 volumio volumio[1347]: info: Remote SSH Started
Oct 14 19:17:36 volumio volumiobt[2014]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)...
Oct 14 19:17:36 volumio autossh[2007]: port set to 0, monitoring disabled
Oct 14 19:17:36 volumio autossh[2007]: starting ssh (count 1)
Oct 14 19:17:36 volumio autossh[2007]: ssh child pid is 2016
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.224 [1976.1976] INFO VolumeManager: [0x1064258]: Setting new playback volume: 75
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.224 [1976.1976] INFO VolumeManager: [0x1064258]: Setting new mute state: 0
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.224 [1976.1976] INFO QobuzConnect: [0x1064c28]: Client initialized!
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.224 [1976.1976] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.230 [1976.1976] INFO LocalConfigManager: [0x1063b38]: Starting Local Configuration server
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.230 [1976.1976] INFO SampleApp: Starting Local configuration server
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.230 [1976.1976] INFO SampleApp: Connected to UNIX socket client 0x104e818
Oct 14 19:17:36 volumio volumio[1347]: info: Access Token successfully retrieved
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Oct 14 19:17:36 volumio volumio[1347]: info: [1791998256235] CoreMusicLibrary::Adding element QOBUZ
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 14 19:17:36 volumio volumio[1347]: Cannot find translation for source QOBUZ
Oct 14 19:17:36 volumio volumio[1347]: info: Stopping AccessToken refresher cron for QOBUZ
Oct 14 19:17:36 volumio volumio[1347]: info: AccessToken refresher cron started for QOBUZ
Oct 14 19:17:36 volumio volumio[1347]: info: Adding QOBUZ REST API Endpoints
Oct 14 19:17:36 volumio volumio[1347]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:36 volumio volumio[1347]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.RVflcqrRRKbfp5gvb7dSCogJvPr1.272a805701c7cfbb57028a837055acdf.state.status'
Oct 14 19:17:36 volumio qobuz-connect[1976]: 20261014 19:17:36.313 [1976.1976] INFO SampleApp: Playback volume changed: 75
Oct 14 19:17:36 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:36 volumio volumiossh-tunnel[2016]: Warning: Permanently added '[eu12.myvolumio.org]:2222' (ED25519) to the list of known hosts.
Oct 14 19:17:36 volumio volumiobt[2015]: INFO:a2dp-agent:Connecting to system bus.
Oct 14 19:17:36 volumio volumiobt[2015]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0
Oct 14 19:17:36 volumio volumiobt[2015]: INFO:a2dp-agent:Enabling infinite discovery on adapter.
Oct 14 19:17:36 volumio volumiobt[2015]: INFO:a2dp-agent:Registering agent.
Oct 14 19:17:36 volumio volumiobt[2015]: INFO:a2dp-agent:Searching for MediaPlayer1 interface...
Oct 14 19:17:36 volumio volumiobt[2015]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work.
Oct 14 19:17:36 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully.
Oct 14 19:17:37 volumio qobuz-connect[1976]: 20261014 19:17:37.888 [1976.2017] INFO SampleApp: API endpoint invoked: get-display-info
Oct 14 19:17:37 volumio qobuz-connect[1976]: 20261014 19:17:37.921 [1976.2017] INFO SampleApp: API endpoint invoked: get-connect-info
Oct 14 19:17:39 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Oct 14 19:17:39 volumio volumio[1347]: info: TidalConnect service stoped!
Oct 14 19:17:39 volumio volumio[1347]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Oct 14 19:17:39 volumio volumio[1347]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Oct 14 19:17:39 volumio sudo[2031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Oct 14 19:17:39 volumio sudo[2031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:17:39 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Oct 14 19:17:39 volumio sudo[2031]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.141 [1976.2017] INFO SampleApp: API endpoint invoked: connect-to-qconnect
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.141 [1976.1976] INFO EndpointManager: [0x1063768]: Updating API endpoint
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.141 [1976.1976] INFO EndpointManager: [0x1063768]: Updating QConnect endpoint
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.141 [1976.1976] INFO ActiveStateManager: [0x1062780]: Setting new active state: active
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.141 [1976.1976] INFO PlaybackSessionManager: [0x1063b58]: Starting playback session maintenance
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.141 [1976.1976] INFO HttpDownloader: [0x1063d48]: Downloading content from: https://www.qobuz.com/api.json/0.2/session/start
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.141 [1976.1976] INFO CloudClient: [0x10643c8]: Connecting to the cloud
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.142 [1976.1976] INFO SampleApp: Renderer is now active
Oct 14 19:17:39 volumio volumio[1347]: info: Executing endpoint tc_getconfig
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Oct 14 19:17:39 volumio vtcs[2034]: STARTING TidalConnect services, version: 1.6.1
Oct 14 19:17:39 volumio vtcs[2034]: STARTED TidalConnect services.
Oct 14 19:17:39 volumio volumio[1347]: info: Executing endpoint tc_connect
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Oct 14 19:17:39 volumio volumio[1347]: info: Connecting to TidalConnect
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: CorePlayQueue::getTrack 0
Oct 14 19:17:39 volumio volumio[1347]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: CorePlayQueue::getTrack 0
Oct 14 19:17:39 volumio volumio[1347]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect
Oct 14 19:17:39 volumio volumio[1347]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.RVflcqrRRKbfp5gvb7dSCogJvPr1.272a805701c7cfbb57028a837055acdf.state.status'
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO CloudClient: [0x10643c8]: Connection established
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Authenticate message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Subscribe message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending JoinSession message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending VolumeChanged message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending VolumeMuted message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending MaxAudioQualityChanged message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.245 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.268 [1976.1976] INFO PlaybackSessionManager: [0x1063b58]: Playback session has been refreshed
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Received SetActive message: active
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Received SetState message:
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Playing state: Playing
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Playback position: 0
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Queue version: 2.1
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Current track: TID: 432085152, QID: 0, Context UUID: bc6014b8-18a0-4daf-96aa-1c3c6944102b
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Next track: TID: 432085153, QID: 1, Context UUID: bc6014b8-18a0-4daf-96aa-1c3c6944102b
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO MediaEngine: [0x1063df0]: Stopping playback, clearing tracks
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO MediaEngine: [0x1063df0]: Initiating playback
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO RendererActionAvailabilityManager: [0x1064480]: Renderer action 'Next' is available
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Received SetLoopMode message: Off
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO PlaybackControlsManager: [0x10641c8]: Setting new loop mode: Off
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO MediaEngine: [0x1063df0]: Setting current track: 432085152, initial offset: 0ms
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Clearing all streams
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: New stream: 1
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO HttpDownloader: [0x11eaa68]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=08e3dd918e5715f985a8ddf31b08bd10&request_ts=1791998259&track_id=432085152
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO HttpDownloader: [0x10a3ef0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=432085152
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO HttpDownloader: [0x1067910]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=e9694726c9f9294712b1387b58833909&request_ts=1791998259&track_id=432085152
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 1]: Running audio stream
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO ProtocolHandler: [0x1064530]: Received SetShuffleMode message: disabled
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO PlaybackControlsManager: [0x10641c8]: Setting new shuffle mode: disabled
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO MediaEngine: [0x1063df0]: Setting next track: 432085153
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: New stream: 2
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO HttpDownloader: [0x106a500]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=d9ad44911bfe2d376be678546b844987&request_ts=1791998259&track_id=432085153
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO HttpDownloader: [0x106ec90]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=432085153
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO HttpDownloader: [0x106efc8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=7d683a18b86b3e33dc714b8ab4ce64e7&request_ts=1791998259&track_id=432085153
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.280 [1976.1976] INFO MediaEngine: [0x1063df0]: Waiting for current stream to start before starting audio renderer
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.411 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 2]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085153&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001859&hmac=lqLdjkdIesaCIIQUZKUJn3cPnbI
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.428 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 2]: stream information have been fetched
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.429 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 1]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085152&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001859&hmac=A1kU76gVpNbRsxi6kD5_9S82TWY
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.449 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 1]: stream information have been fetched
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.449 [1976.1976] INFO UrlAudioSource: [0x12219e8]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085152&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001859&hmac=A1kU76gVpNbRsxi6kD5_9S82TWY
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.449 [1976.1976] INFO ContentFetcher: [0x106a628]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085152&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001859&hmac=A1kU76gVpNbRsxi6kD5_9S82TWY, offset: 0
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.449 [1976.1976] INFO AudioRenderer: [0x1064010]: Starting audio renderer, initial playback state: Playing
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.449 [1976.1976] INFO SampleApp: [Stream 1]: New audio stream (starting from 0ms)
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: QobuzConnect: setActiveState()
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: QobuzConnect: Set Qobuz connect default volume to 100
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.451 [1976.1976] INFO VolumeManager: [0x1064258]: Setting new playback volume: 100
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: QobuzConnect: Stopping currently active service
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioStop
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::stop
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::serviceStop
Oct 14 19:17:39 volumio volumio[1347]: info: Received STOP, but no service to execute it
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: CorePlayQueue::getTrack 0
Oct 14 19:17:39 volumio volumio[1347]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received qobuzconnect
Oct 14 19:17:39 volumio volumio[1347]: info: QobuzConnect: setActiveState(): setting Volatile state to qobuzconnect
Oct 14 19:17:39 volumio volumio[1347]: info: QobuzConnect: setActiveState() completed, send playback confirmation
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.454 [1976.1976] INFO SampleApp: Initiating playback, initial state: Playing
Oct 14 19:17:39 volumio volumio[1347]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.RVflcqrRRKbfp5gvb7dSCogJvPr1.272a805701c7cfbb57028a837055acdf.state.status'
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO SampleApp: Playback state changed: Playing
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO StreamingEventReporter: [0x1064948]: Reporting streaming started event
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO HttpDownloader: [0x10649a0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO ProtocolHandler: [0x1064530]: Need to send state update
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending StateUpdated message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 2]: Metadata became available:
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Title: Anauralia
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Artist: Victor Solano
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album: Sundate
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album art URL: https://static.qobuz.com/images/covers/f7/2e/bt4i57tir2ef7_600.jpg
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.475 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending FileAudioQualityChanged message
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.476 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.476 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending DeviceAudioQualityChanged message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.476 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.478 [1976.1976] INFO VolumeManager: [0x1064258]: Setting new playback volume: 100
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.478 [1976.1976] INFO VolumeManager: [0x1064258]: Setting new mute state: 0
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.RVflcqrRRKbfp5gvb7dSCogJvPr1.272a805701c7cfbb57028a837055acdf.state.track'
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 1]: Metadata became available:
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Title: Rise
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Artist: Victor Solano
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album: Sundate
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album art URL: https://static.qobuz.com/images/covers/f7/2e/bt4i57tir2ef7_600.jpg
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO SampleApp: [Stream 1]: Stream metadata became available:
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO SampleApp: Title: Rise
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO SampleApp: Artist: Victor Solano
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO SampleApp: Album: Sundate
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.506 [1976.1976] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/f7/2e/bt4i57tir2ef7_600.jpg
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2.
Oct 14 19:17:39 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Oct 14 19:17:39 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Oct 14 19:17:39 volumio sudo[1806]: pam_unix(sudo:session): session closed for user root
Oct 14 19:17:39 volumio volumio[1347]: info: Upmpdcli Daemon Started
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.573 [1976.1976] INFO UrlAudioSource: [0x12219e8]: Content info extracted
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.573 [1976.1976] INFO UrlAudioSource: [0x12219e8]: Size: 151414822
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.574 [1976.2054] INFO AudioDecoder: [0x1279d90]: Stream info:
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.574 [1976.2054] INFO AudioDecoder: [0x1279d90]: Total samples: 38964096
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.574 [1976.2054] INFO AudioDecoder: [0x1279d90]: Sample rate: 88200
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.574 [1976.2054] INFO AudioDecoder: [0x1279d90]: Channel count: 2
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.574 [1976.2054] INFO AudioDecoder: [0x1279d90]: Bits per sample: 24
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.574 [1976.2054] INFO AudioDecoder: [0x1279d90]: Duration: 441769
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.574 [1976.1976] INFO UrlAudioSource: [0x12219e8]: Audio properties have changed
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.602 [1976.1976] INFO SampleApp: Playback volume changed: 100
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.602 [1976.1976] INFO ProtocolHandler: [0x1064530]: Volume changed: 100
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.602 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending VolumeChanged message
Oct 14 19:17:39 volumio qobuz-connect[1976]: 20261014 19:17:39.602 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:39 volumio volumio[1347]: info: QobuzConnect: Volume received from daemon: 100
Oct 14 19:17:39 volumio volumio[1347]: info: VolumeController::SetAlsaVolume100
Oct 14 19:17:39 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:39 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:41 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Oct 14 19:17:41 volumio volumio[1347]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Oct 14 19:17:41 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:42 volumio volumio[1347]: info: TidalConnect service started!
Oct 14 19:17:42 volumio volumio[1347]: [Metrics] CommandRouter: 27s 943.95ms
Oct 14 19:17:42 volumio volumio[1347]: info: CoreCommandRouter::volumiosetStartupVolume
Oct 14 19:17:42 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:42 volumio volumio[1347]: info: VolumeController:: Setting startup Volume 100
Oct 14 19:17:42 volumio volumio[1347]: info: VolumeController::SetAlsaVolume100
Oct 14 19:17:42 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:42 volumio volumio[1347]: info: CoreCommandRouter::Close All Modals sent
Oct 14 19:17:42 volumio volumio[1347]: info: CoreCommandRouter::Close All Modals sent
Oct 14 19:17:42 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:42 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:42 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:42 volumio volumio[1347]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav
Oct 14 19:17:42 volumio volumio[1347]: aplay: main:831: audio open error: Device or resource busy
Oct 14 19:17:43 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Oct 14 19:17:43 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Oct 14 19:17:43 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Oct 14 19:17:45 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Oct 14 19:17:45 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:17:45 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Oct 14 19:17:46 volumio volumio-remote-updater[1000]: Test mode disabled
Oct 14 19:17:46 volumio volumio-remote-updater[1000]: Alpha mode disabled
Oct 14 19:17:46 volumio volumio-remote-updater[1000]: Alpha legacy test mode disabled
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Oct 14 19:17:46 volumio volumio[1347]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Oct 14 19:17:46 volumio upmpdcli[2093]: writing RSA key
Oct 14 19:17:46 volumio volumio5-onboarding[1578]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded
Oct 14 19:17:46 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Oct 14 19:17:46 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::volumioGetBrowseSources
Oct 14 19:17:46 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Oct 14 19:17:46 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1.
Oct 14 19:17:46 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Oct 14 19:17:47 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Oct 14 19:17:47 volumio volumio5-onboarding[2105]: time=2026-10-14T19:17:47.024+02:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z
Oct 14 19:17:47 volumio volumio[1347]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5
Oct 14 19:17:47 volumio volumio[1347]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5
Oct 14 19:17:47 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:17:47 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:17:47 volumio volumio5-onboarding[2105]: time=2026-10-14T19:17:47.032+02:00 level=INFO msg="system info for 272a805701c7cfbb57028a837055acdf" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.096
Oct 14 19:17:47 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:17:47 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Oct 14 19:17:47 volumio volumio5-onboarding[2105]: time=2026-10-14T19:17:47.046+02:00 level=INFO msg="enabling local network discovery"
Oct 14 19:17:47 volumio volumio5-onboarding[2105]: time=2026-10-14T19:17:47.059+02:00 level=INFO msg="bootstrapping state" hasInternet=true
Oct 14 19:17:47 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:17:47 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:17:47 volumio volumio-remote-updater[1000]: Test mode disabled
Oct 14 19:17:47 volumio volumio-remote-updater[1000]: Alpha mode disabled
Oct 14 19:17:47 volumio volumio-remote-updater[1000]: Alpha legacy test mode disabled
Oct 14 19:17:47 volumio volumio[1347]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Oct 14 19:17:47 volumio volumio5-onboarding[2105]: time=2026-10-14T19:17:47.436+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:17:47 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Oct 14 19:17:48 volumio volumio5-onboarding[2105]: time=2026-10-14T19:17:48.649+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=RVflcqrRRKbfp5gvb7dSCogJvPr1 tokenExpiry=2026-10-14T20:17:48.649+02:00
Oct 14 19:17:49 volumio volumio[1347]: info: BOOT COMPLETED
Oct 14 19:17:49 volumio qobuz-connect[1976]: 20261014 19:17:49.475 [1976.1976] INFO ProtocolHandler: [0x1064530]: Need to send state update
Oct 14 19:17:49 volumio qobuz-connect[1976]: 20261014 19:17:49.475 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending StateUpdated message
Oct 14 19:17:49 volumio qobuz-connect[1976]: 20261014 19:17:49.476 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:17:49 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:49 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:49 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:49 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:17:49 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:49 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:59 volumio qobuz-connect[1976]: 20261014 19:17:59.475 [1976.1976] INFO ProtocolHandler: [0x1064530]: Need to send state update
Oct 14 19:17:59 volumio qobuz-connect[1976]: 20261014 19:17:59.475 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending StateUpdated message
Oct 14 19:17:59 volumio qobuz-connect[1976]: 20261014 19:17:59.475 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:17:59 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:17:59 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:17:59 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:17:59 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:17:59 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:17:59 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:01 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Oct 14 19:18:02 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Oct 14 19:18:02 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Oct 14 19:18:09 volumio qobuz-connect[1976]: 20261014 19:18:09.476 [1976.1976] INFO ProtocolHandler: [0x1064530]: Need to send state update
Oct 14 19:18:09 volumio qobuz-connect[1976]: 20261014 19:18:09.476 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending StateUpdated message
Oct 14 19:18:09 volumio qobuz-connect[1976]: 20261014 19:18:09.476 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:18:09 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:09 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:18:09 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:18:09 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:18:09 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:18:09 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:19 volumio qobuz-connect[1976]: 20261014 19:18:19.476 [1976.1976] INFO ProtocolHandler: [0x1064530]: Need to send state update
Oct 14 19:18:19 volumio qobuz-connect[1976]: 20261014 19:18:19.476 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending StateUpdated message
Oct 14 19:18:19 volumio qobuz-connect[1976]: 20261014 19:18:19.476 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:18:19 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:19 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:18:19 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:18:19 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:18:19 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:18:19 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.134+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.132:58962
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.159+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.132:58962 @ 0x3400b10" latency=-30.222955ms platform=PLATFORM_ANDROID version=6.260930.0
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.160+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.132:58962 @ 0x3400b10" latency=-31.053343ms timeout=20s
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.160+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10"
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Oct 14 19:18:21 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:18:21 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.163+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" name=Volumio
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.165+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" language=de
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.166+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" timezone=Europe/Berlin
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.166+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" available=true connected=true macAddress=d8:3a:dd:a8:04:3b ip4Address=192.168.1.112/24 ip6Address=
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.169+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" available=true connected=false macAddress= ip4Address= ip6Address= ssid=
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.169+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" setupComplete=true
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Oct 14 19:18:21 volumio volumio[1347]: amixer -c 0 info | grep "vc4-hdmi-0"
Oct 14 19:18:21 volumio volumio[1347]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0'
Oct 14 19:18:21 volumio volumio[1347]: amixer -c 1 info | grep "vc4-hdmi-1"
Oct 14 19:18:21 volumio volumio[1347]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1'
Oct 14 19:18:21 volumio volumio[1347]: amixer -c 2 info | grep "snd_rpi_hifiberry_dac"
Oct 14 19:18:21 volumio volumio[1347]: Card sysdefault:2 'sndrpihifiberry'/'snd_rpi_hifiberry_dac'
Oct 14 19:18:21 volumio volumio[1347]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2
Oct 14 19:18:21 volumio volumio[1347]: /bin/sh: 1: /usr/local/bin/alsacap: not found
Oct 14 19:18:21 volumio volumio[1347]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"}
Oct 14 19:18:21 volumio volumio[1347]: amixer -c 2 info | grep "Soekris dam 1021"
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.226+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" selectedOutputId=2
Oct 14 19:18:21 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:18:21 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.243+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" currentVersion=4.096 latestVersion=4.119
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.243+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.132:58962 @ 0x3400b10" status=UPDATE_STATUS_NONE progress=0
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.244+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" userId=RVflcqrRRKbfp5gvb7dSCogJvPr1
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.244+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" providers=9
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.244+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" plugins=78
Oct 14 19:18:21 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.246+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" state=STATUS_PLAYING positionMs=39901 volume=100
Oct 14 19:18:21 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:21.246+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" id= title=Rise
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.148+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.132:58962 @ 0x3400b10" latency=58.836476ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.168+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.267+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=http://pushupdates.volumio.org duration=98.364813ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.279+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=110.644639ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.314+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=144.807228ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.344+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://functions.volumio.cloud duration=175.006161ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.360+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://functions.volumio.cloud duration=191.12681ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.374+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=205.206963ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.380+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=http://cddb.volumio.org duration=210.707798ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF"
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.387+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://www.googleapis.com duration=218.820205ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.391+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://securetoken.googleapis.com duration=222.477046ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.399+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=230.026617ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.576+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=http://plugins.volumio.org duration=407.097422ms
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.629+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://database.volumio.cloud duration=459.450322ms
Oct 14 19:18:22 volumio sudo[2219]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Oct 14 19:18:22 volumio sudo[2219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:18:22 volumio sudo[2219]: pam_unix(sudo:session): session closed for user root
Oct 14 19:18:22 volumio sudo[2221]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Oct 14 19:18:22 volumio sudo[2221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:18:22 volumio sudo[2221]: pam_unix(sudo:session): session closed for user root
Oct 14 19:18:22 volumio volumio[1347]: verbose: New Socket.io Connection to 192.168.1.112 from 192.168.1.132 UA: Mozilla/5.0 (Linux; Android 17; 25113PN0EG Build/CP2A.260605.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 6
Oct 14 19:18:22 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:22.711+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.132:58962 @ 0x3400b10" latency=-33.184471ms timeout=10s endpoint=https://google.com duration=542.118323ms
Oct 14 19:18:22 volumio sudo[2225]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Oct 14 19:18:22 volumio sudo[2225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:18:22 volumio sudo[2225]: pam_unix(sudo:session): session closed for user root
Oct 14 19:18:22 volumio sudo[2227]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Oct 14 19:18:22 volumio sudo[2227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 14 19:18:22 volumio sudo[2227]: pam_unix(sudo:session): session closed for user root
Oct 14 19:18:22 volumio volumio[1347]: verbose: New Socket.io Connection to 192.168.1.112 from 192.168.1.132 UA: Mozilla/5.0 (Linux; Android 17; 25113PN0EG Build/CP2A.260605.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 7
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetQueue
Oct 14 19:18:23 volumio volumio[1347]: info: CoreStateMachine::getQueue
Oct 14 19:18:23 volumio volumio[1347]: info: CorePlayQueue::getQueue
Oct 14 19:18:23 volumio volumio[1347]: info: Listing playlists
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Oct 14 19:18:23 volumio volumio[1347]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Oct 14 19:18:23 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:18:23 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:18:23 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:18:23 volumio volumio[1347]: verbose: New Socket.io Connection to 192.168.1.112:3000 from 192.168.1.132 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Oct 14 19:18:23 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Oct 14 19:18:24 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Oct 14 19:18:24 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:18:24 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:18:24 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:18:24 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:18:24 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:18:24 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:24 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:18:25 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Oct 14 19:18:25 volumio volumio[1347]: info: CURURI: music-library
Oct 14 19:18:25 volumio volumio[1347]: info: Preload queue cleared
Oct 14 19:18:25 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Oct 14 19:18:25 volumio volumio[1347]: info: CURURI: music-library/NAS
Oct 14 19:18:25 volumio volumio[1347]: info: Preload queue cleared
Oct 14 19:18:26 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Oct 14 19:18:26 volumio volumio[1347]: info: CURURI: music-library/NAS/CD_FLAC
Oct 14 19:18:26 volumio volumio[1347]: info: Preload queue cleared
Oct 14 19:18:26 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 14 19:18:26 volumio volumio[1347]: info: Received Get System Info
Oct 14 19:18:26 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 14 19:18:26 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 14 19:18:26 volumio volumio[1347]: info: Discovery: Getting this device information
Oct 14 19:18:26 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:26 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 14 19:18:29 volumio qobuz-connect[1976]: 20261014 19:18:29.476 [1976.1976] INFO ProtocolHandler: [0x1064530]: Need to send state update
Oct 14 19:18:29 volumio qobuz-connect[1976]: 20261014 19:18:29.476 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending StateUpdated message
Oct 14 19:18:29 volumio qobuz-connect[1976]: 20261014 19:18:29.476 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:18:29 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:29 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:18:29 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:18:29 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:18:29 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:18:29 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:29 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:29.482+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" state=STATUS_PLAYING positionMs=49901 volume=100
Oct 14 19:18:29 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:29.482+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" id= title=Rise
Oct 14 19:18:30 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Oct 14 19:18:30 volumio volumio[1347]: info: CURURI: music-library/NAS/CD_FLAC/Diana Krall
Oct 14 19:18:30 volumio volumio[1347]: info: Preload queue cleared
Oct 14 19:18:32 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Oct 14 19:18:33 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Oct 14 19:18:33 volumio volumio[1347]: info: CURURI: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs
Oct 14 19:18:33 volumio volumio[1347]: info: Preload queue cleared
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/01 Diana Krall - Jingle Bells.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/02 Diana Krall - Let It Snow.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/03 Diana Krall - The Christmas Song.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/04 Diana Krall - Winter Wonderland.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/05 Diana Krall - I'll Be Home For Christmas.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/06 Diana Krall - Christmas Time Is Here.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/07 Diana Krall - Santa Claus Is Coming To Town.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/08 Diana Krall - Have Yourself A Merry Little Christmas.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/09 Diana Krall - White Christmas.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/10 Diana Krall - What Are You Doing New Year's Eve.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/11 Diana Krall - Sleigh Ride.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Preloading song: music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/12 Diana Krall - Count Your Blessings Instead Of Sheep.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/01 Diana Krall - Jingle Bells.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F01%20Diana%20Krall%20-%20Jingle%20Bells.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/01 Diana Krall - Jingle Bells.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/02 Diana Krall - Let It Snow.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F02%20Diana%20Krall%20-%20Let%20It%20Snow.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/02 Diana Krall - Let It Snow.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/03 Diana Krall - The Christmas Song.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F03%20Diana%20Krall%20-%20The%20Christmas%20Song.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/03 Diana Krall - The Christmas Song.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/04 Diana Krall - Winter Wonderland.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F04%20Diana%20Krall%20-%20Winter%20Wonderland.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/04 Diana Krall - Winter Wonderland.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/05 Diana Krall - I'll Be Home For Christmas.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F05%20Diana%20Krall%20-%20I'll%20Be%20Home%20For%20Christmas.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/05 Diana Krall - I'll Be Home For Christmas.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/06 Diana Krall - Christmas Time Is Here.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F06%20Diana%20Krall%20-%20Christmas%20Time%20Is%20Here.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/06 Diana Krall - Christmas Time Is Here.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/07 Diana Krall - Santa Claus Is Coming To Town.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F07%20Diana%20Krall%20-%20Santa%20Claus%20Is%20Coming%20To%20Town.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/07 Diana Krall - Santa Claus Is Coming To Town.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/08 Diana Krall - Have Yourself A Merry Little Christmas.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F08%20Diana%20Krall%20-%20Have%20Yourself%20A%20Merry%20Little%20Christmas.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/08 Diana Krall - Have Yourself A Merry Little Christmas.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/09 Diana Krall - White Christmas.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F09%20Diana%20Krall%20-%20White%20Christmas.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/09 Diana Krall - White Christmas.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/10 Diana Krall - What Are You Doing New Year's Eve.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F10%20Diana%20Krall%20-%20What%20Are%20You%20Doing%20New%20Year's%20Eve.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/10 Diana Krall - What Are You Doing New Year's Eve.flac
Oct 14 19:18:33 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/11 Diana Krall - Sleigh Ride.flac in service mpd
Oct 14 19:18:33 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F11%20Diana%20Krall%20-%20Sleigh%20Ride.flac&metadata=false
Oct 14 19:18:33 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/11 Diana Krall - Sleigh Ride.flac
Oct 14 19:18:34 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Christmas Songs/12 Diana Krall - Count Your Blessings Instead Of Sheep.flac in service mpd
Oct 14 19:18:34 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Christmas%20Songs/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FChristmas%20Songs%2F12%20Diana%20Krall%20-%20Count%20Your%20Blessings%20Instead%20Of%20Sheep.flac&metadata=false
Oct 14 19:18:34 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Christmas Songs/12 Diana Krall - Count Your Blessings Instead Of Sheep.flac
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 14 19:18:37 volumio volumio[1347]: info: CoreStateMachine::ClearQueue
Oct 14 19:18:37 volumio volumio[1347]: info: CoreStateMachine::stop
Oct 14 19:18:37 volumio volumio[1347]: info: CoreStateMachine::serviceStop
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::serviceStop
Oct 14 19:18:37 volumio volumio[1347]: info: QobuzConnect: Received stop
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:37 volumio volumio[1347]: info: CorePlayQueue::clearPlayQueue
Oct 14 19:18:37 volumio volumio[1347]: info: CorePlayQueue::saveQueue
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioPushQueue
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.161 [1976.1976] INFO MediaEngine: [0x1063df0]: Stopping playback, keeping tracks
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.161 [1976.1976] INFO AudioRenderer: [0x1064010]: Stopping audio renderer
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.161 [1976.1976] INFO SampleApp: Stopping playback
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.162 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Clearing all streams
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.162 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 1]: Disposing of audio stream
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.162 [1976.1976] INFO ContentFetcher: [0x106a628]: Canceling download
Oct 14 19:18:37 volumio volumio[1347]: info: CoreStateMachine::addQueueItems
Oct 14 19:18:37 volumio volumio[1347]: info: CorePlayQueue::addQueueItems
Oct 14 19:18:37 volumio volumio[1347]: info: Preload queue cleared
Oct 14 19:18:37 volumio volumio[1347]: info: Adding Item to queue: music-library/NAS/CD_FLAC/Diana Krall/Diana Krall - Live In Paris [2002]
Oct 14 19:18:37 volumio volumio[1347]: info: Exploding uri music-library/NAS/CD_FLAC/Diana Krall/Diana Krall - Live In Paris [2002] in service mpd
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: New stream: 3
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO HttpDownloader: [0x106a500]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=916b6663d07b970003dd7de78b9021b0&request_ts=1791998317&track_id=432085152
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO HttpDownloader: [0x109cfa8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=432085152
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO HttpDownloader: [0x1213cd8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=e26bf0d0190f459bc6017ac1902281b1&request_ts=1791998317&track_id=432085152
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 3]: Running audio stream
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: New stream: 4
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO HttpDownloader: [0x11eaa68]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=07f7b646cbffa7cd8de8d5efa7d8e8a1&request_ts=1791998317&track_id=432085153
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO HttpDownloader: [0x1278030]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=432085153
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.165 [1976.1976] INFO HttpDownloader: [0x11cc8e8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=e8ec253ddd95bc61fc041476378a0151&request_ts=1791998317&track_id=432085153
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.166 [1976.1976] INFO SampleApp: Playback state changed: Stopped
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.166 [1976.1976] INFO StreamingEventReporter: [0x1064948]: Reporting streaming ended event
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.166 [1976.1976] INFO HttpDownloader: [0x10649a0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.166 [1976.1976] INFO ProtocolHandler: [0x1064530]: Need to send state update
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.166 [1976.1976] INFO QConnectMessageSender: [0x10a1b88]: Sending StateUpdated message
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.166 [1976.1976] INFO SampleApp: [Stream 1]: Audio stream has been disposed of
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.166 [1976.1976] INFO QwspMessageSender: [0x109fb60]: Sending Payload message
Oct 14 19:18:37 volumio volumio[1347]: info: QobuzConnect: playback_stop received, deferred solved
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::servicePushState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreStateMachine::pushState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioPushState
Oct 14 19:18:37 volumio volumio[1347]: info: CoreCommandRouter::volumioGetState
Oct 14 19:18:37 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:37.192+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" state=STATUS_PAUSED positionMs=49901 volume=100
Oct 14 19:18:37 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:37.192+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" id= title=Rise
Oct 14 19:18:37 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:37.192+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" state=STATUS_PAUSED positionMs=0 volume=100
Oct 14 19:18:37 volumio volumio5-onboarding[2105]: time=2026-10-14T19:18:37.193+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.132:58962 @ 0x3400b10" id= title=Rise
Oct 14 19:18:37 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Live%20In%20Paris/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FDiana%20Krall%20-%20Live%20In%20Paris%20%5B2002%5D%2F00%20-%20Live%20In%20Paris.cue&metadata=false
Oct 14 19:18:37 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Diana Krall - Live In Paris [2002]/00 - Live In Paris.cue
Oct 14 19:18:37 volumio volumio[1347]: info: ALBUMART /albumart?cacheid=197&web=Diana%20Krall/Live%20In%20Paris/extralarge&path=%2Fmnt%2FNAS%2FCD_FLAC%2FDiana%20Krall%2FDiana%20Krall%20-%20Live%20In%20Paris%20%5B2002%5D%2F00%20-%20Live%20In%20Paris.cue&metadata=false
Oct 14 19:18:37 volumio volumio[1347]: info: URI /mnt/NAS/CD_FLAC/Diana Krall/Diana Krall - Live In Paris [2002]/00 - Live In Paris.cue
Oct 14 19:18:37 volumio volumio[1347]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 14 19:18:37 volumio volumio[1347]: Error: Unable to resolve or reject the same promise twice
Oct 14 19:18:37 volumio volumio[1347]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43)
Oct 14 19:18:37 volumio volumio[1347]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21
Oct 14 19:18:37 volumio volumio[1347]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3)
Oct 14 19:18:37 volumio volumio[1347]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12)
Oct 14 19:18:37 volumio volumio[1347]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12)
Oct 14 19:18:37 volumio volumio[1347]: at Socket.emit (node:events:514:28)
Oct 14 19:18:37 volumio volumio[1347]: at addChunk (node:internal/streams/readable:343:12)
Oct 14 19:18:37 volumio volumio[1347]: at readableAddChunk (node:internal/streams/readable:312:11)
Oct 14 19:18:37 volumio volumio[1347]: at Readable.push (node:internal/streams/readable:253:10)
Oct 14 19:18:37 volumio volumio[1347]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)
Oct 14 19:18:37 volumio volumio[1347]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.304 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 3]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085152&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001917&hmac=lpMGkvCHQaxmdSxI_JahhL8av7I
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.312 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 4]: Metadata became available:
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.312 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Title: Anauralia
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.312 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Artist: Victor Solano
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.312 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album: Sundate
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.312 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album art URL: https://static.qobuz.com/images/covers/f7/2e/bt4i57tir2ef7_600.jpg
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.318 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 3]: Metadata became available:
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.318 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Title: Rise
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.318 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Artist: Victor Solano
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.318 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album: Sundate
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.318 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: Album art URL: https://static.qobuz.com/images/covers/f7/2e/bt4i57tir2ef7_600.jpg
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.329 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 4]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085153&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001917&hmac=gs6CyeIe81wsn-VVwue9e7FQ8q8
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 3]: stream information have been fetched
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO UrlAudioSource: [0x121ce28]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085152&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001917&hmac=lpMGkvCHQaxmdSxI_JahhL8av7I
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO ContentFetcher: [0x13117d0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=9721972&eid=432085152&fmt=7&profile=raw&app_id=174516466&cid=3707462&etsp=1792001917&hmac=lpMGkvCHQaxmdSxI_JahhL8av7I, offset: 0
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO SampleApp: [Stream 3]: New audio stream (starting from 0ms)
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO SampleApp: [Stream 3]: Stream metadata became available:
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO SampleApp: Title: Rise
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO SampleApp: Artist: Victor Solano
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO SampleApp: Album: Sundate
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.331 [1976.1976] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/f7/2e/bt4i57tir2ef7_600.jpg
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.377 [1976.1976] INFO UrlAudioSource: [0x121ce28]: Content info extracted
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.377 [1976.1976] INFO UrlAudioSource: [0x121ce28]: Size: 151414822
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.378 [1976.2274] INFO AudioDecoder: [0x1278a28]: Stream info:
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.378 [1976.2274] INFO AudioDecoder: [0x1278a28]: Total samples: 38964096
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.378 [1976.2274] INFO AudioDecoder: [0x1278a28]: Sample rate: 88200
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.378 [1976.2274] INFO AudioDecoder: [0x1278a28]: Channel count: 2
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.378 [1976.2274] INFO AudioDecoder: [0x1278a28]: Bits per sample: 24
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.378 [1976.2274] INFO AudioDecoder: [0x1278a28]: Duration: 441769
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.378 [1976.1976] INFO UrlAudioSource: [0x121ce28]: Audio properties have changed
Oct 14 19:18:37 volumio qobuz-connect[1976]: 20261014 19:18:37.402 [1976.1976] INFO AudioStreamManager: [0x1063ed8]: [Stream 4]: stream information have been fetched
Oct 14 19:18:37 volumio sudo[2277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-14 19:17'
Oct 14 19:18:37 volumio sudo[2277]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026"
VOLUMIO_VERSION="4.096"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"