Apr 10 13:36:00 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 10 13:36:00 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 10 13:36:11 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:36:11+02:00" level=trace msg="sent dealer ping" Apr 10 13:36:11 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:36:11+02:00" level=trace msg="received dealer pong" Apr 10 13:36:12 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 10 13:36:12 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 10 13:36:12 volumio-skalisty volumio[1024]: info: Streaming services startup Apr 10 13:36:12 volumio-skalisty volumio[1024]: info: Starting Streaming Daemon Apr 10 13:36:13 volumio-skalisty sudo[1586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 10 13:36:13 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 10 13:36:13 volumio-skalisty sudo[1586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:13 volumio-skalisty sudo[1586]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:13 volumio-skalisty volumio[1024]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 10 13:36:13 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 13:36:13 volumio-skalisty volumio[1024]: info: Initializing connection to go-librespot Websocket Apr 10 13:36:14 volumio-skalisty volumio[1024]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Apr 10 13:36:14 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:14 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 10 13:36:14 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:14 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 10 13:36:14 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 13:36:14 volumio-skalisty volumio[1024]: error: Cannot start Volumio Streaming Daemon Apr 10 13:36:14 volumio-skalisty volumio[1024]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 10 13:36:14 volumio-skalisty volumio[1024]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 10 13:36:14 volumio-skalisty volumio5-onboarding[1503]: failed to bootstrap state: failed to get available plugins: could not get available plugins: could not check MyVolumio login status: context deadline exceeded Apr 10 13:36:14 volumio-skalisty systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 10 13:36:14 volumio-skalisty systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 10 13:36:14 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 13:36:14 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:36:14+02:00" level=debug msg="new websocket client" Apr 10 13:36:14 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 10 13:36:15 volumio-skalisty systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Apr 10 13:36:15 volumio-skalisty systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 10 13:36:15 volumio-skalisty systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 10 13:36:15 volumio-skalisty volumio5-onboarding[1595]: time=2026-04-10T13:36:15.237+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: Connection to go-librespot Websocket established Apr 10 13:36:15 volumio-skalisty volumio[1024]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Apr 10 13:36:15 volumio-skalisty volumio[1024]: 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: 10 Apr 10 13:36:15 volumio-skalisty volumio[1024]: 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: 10 Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: Received Get System Info Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: Discovery: Getting this device information Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 13:36:15 volumio-skalisty volumio5-onboarding[1595]: time=2026-04-10T13:36:15.837+02:00 level=INFO msg="system info for a210cfd02c235ddc04fcf2316b1a7933" deviceName=Volumio-Skalisty deviceVariant=volumio deviceModel= softwareVersion=4.119 Apr 10 13:36:15 volumio-skalisty volumio5-onboarding[1595]: time=2026-04-10T13:36:15.939+02:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: Received Get System Info Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: Discovery: Getting this device information Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 13:36:16 volumio-skalisty volumio-remote-updater[586]: Test mode disabled Apr 10 13:36:16 volumio-skalisty volumio-remote-updater[586]: Alpha mode disabled Apr 10 13:36:16 volumio-skalisty volumio-remote-updater[586]: Alpha legacy test mode disabled Apr 10 13:36:16 volumio-skalisty volumio[1024]: SPOTIFY: User informations: {"country":"PL","display_name":"5k18a","email":"pestycyd@wp.pl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/5k18a"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/5k18a","id":"5k18a","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85c0f3b76b3ac523a40c4efce4","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82c0f3b76b3ac523a40c4efce4","width":64}],"product":"premium","type":"user","uri":"spotify:user:5k18a"} Apr 10 13:36:16 volumio-skalisty volumio[1024]: info: Spotify Successfully logged in Apr 10 13:36:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 10 13:36:16 volumio-skalisty volumio[1024]: info: [1775820976049] CoreMusicLibrary::Adding element Spotify Apr 10 13:36:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 13:36:16 volumio-skalisty volumio[1024]: Cannot find translation for source Spotify Apr 10 13:36:16 volumio-skalisty volumio[1024]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 10 13:36:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 13:36:17 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 13:36:17 volumio-skalisty volumio-remote-updater[586]: Test mode disabled Apr 10 13:36:17 volumio-skalisty volumio-remote-updater[586]: Alpha mode disabled Apr 10 13:36:17 volumio-skalisty volumio-remote-updater[586]: Alpha legacy test mode disabled Apr 10 13:36:17 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 10 13:36:17 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 13:36:18 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:36:18 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:18 volumio-skalisty volumio[1024]: info: Getting Spotify volume Apr 10 13:36:18 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 13:36:18 volumio-skalisty volumio[1024]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 10 13:36:18 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: Received Get System Info Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: Discovery: Getting this device information Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: Spotify volume: 100 Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 10 13:36:19 volumio-skalisty volumio5-onboarding[1595]: time=2026-04-10T13:36:19.621+02:00 level=INFO msg="enabling local network discovery" Apr 10 13:36:19 volumio-skalisty volumio5-onboarding[1595]: time=2026-04-10T13:36:19.716+02:00 level=INFO msg="enabling BLE discovery" Apr 10 13:36:19 volumio-skalisty volumio[1024]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetBrowseSources Apr 10 13:36:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 10 13:36:20 volumio-skalisty volumio5-onboarding[1595]: time=2026-04-10T13:36:20.709+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 10 13:36:20 volumio-skalisty volumio[1024]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 10 13:36:20 volumio-skalisty upmpdcli[1623]: writing RSA key Apr 10 13:36:22 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:36:22 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:22 volumio-skalisty volumio[1024]: info: MyVolumio token set successfully Apr 10 13:36:22 volumio-skalisty volumio[1024]: info: MYVOLUMIO: Adding device Apr 10 13:36:22 volumio-skalisty volumio[1024]: info: MYVOLUMIO: Evaluating Server Apr 10 13:36:23 volumio-skalisty volumio[1024]: info: MyVolumio Plan changed: premium Apr 10 13:36:23 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 10 13:36:23 volumio-skalisty volumio[1024]: info: Removing browser output: myVolumio user plan is not superstar Apr 10 13:36:24 volumio-skalisty volumio[1024]: info: Removing audio output: Apr 10 13:36:24 volumio-skalisty volumio[1024]: info: MYVOLUMIO: Adding device Apr 10 13:36:24 volumio-skalisty volumio[1024]: info: MYVOLUMIO: Evaluating Server Apr 10 13:36:24 volumio-skalisty volumio[1024]: info: Remote config written successfully Apr 10 13:36:24 volumio-skalisty volumio[1024]: info: Starting Tunnel 1 Apr 10 13:36:24 volumio-skalisty volumio[1024]: info: Starting Tunnel Connection Checker Apr 10 13:36:24 volumio-skalisty volumio[1024]: info: Completed starting MyVolumio Plugin Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: MYVolumio Device enabled Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: MyVolumio status changed Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: Streaming services startup Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: Starting Streaming Daemon Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: Setting Geolocation for MyVolumio to eu7 Apr 10 13:36:25 volumio-skalisty sudo[1667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 10 13:36:25 volumio-skalisty sudo[1667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:25 volumio-skalisty sudo[1667]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: Setting Geolocation for MyVolumio to eu9 Apr 10 13:36:25 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:26 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:26 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:26 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:26 volumio-skalisty volumio[1024]: error: Cannot start Volumio Streaming Daemon Apr 10 13:36:26 volumio-skalisty volumio[1024]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 10 13:36:26 volumio-skalisty volumio[1024]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 10 13:36:26 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 10 13:36:26 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:26 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 10 13:36:27 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 10 13:36:27 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 10 13:36:27 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Apr 10 13:36:27 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 10 13:36:38 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Apr 10 13:36:38 volumio-skalisty sudo[1703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 10 13:36:38 volumio-skalisty sudo[1703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:38 volumio-skalisty sudo[1703]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:39 volumio-skalisty volumio[1024]: info: MRS: MultiRoom plugin initialized Apr 10 13:36:39 volumio-skalisty volumio[1024]: info: MRS: STOPPING SNAPCLIENT Apr 10 13:36:39 volumio-skalisty volumio[1024]: info: MRS: Snap server stop Apr 10 13:36:39 volumio-skalisty volumio[1024]: info: MRS: STOPPING volumioStreaming Apr 10 13:36:39 volumio-skalisty sudo[1720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 10 13:36:39 volumio-skalisty sudo[1720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:39 volumio-skalisty sudo[1724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 10 13:36:39 volumio-skalisty sudo[1724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:39 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 10 13:36:39 volumio-skalisty sudo[1722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 10 13:36:39 volumio-skalisty sudo[1722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:40 volumio-skalisty sudo[1728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 10 13:36:40 volumio-skalisty sudo[1728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:40 volumio-skalisty sudo[1728]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:40 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 10 13:36:40 volumio-skalisty sudo[1722]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:40 volumio-skalisty sudo[1724]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:40 volumio-skalisty sudo[1720]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:40 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 10 13:36:40 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 10 13:36:40 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: Preparing to generate the ALSA configuration file Apr 10 13:36:41 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:36:41+02:00" level=trace msg="sent dealer ping" Apr 10 13:36:41 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:36:41+02:00" level=trace msg="received dealer pong" Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: Updating MyVolumio device info Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: Updating MyVolumio device info Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:41 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: Successfully Added MyVolumio device Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: Successfully Added MyVolumio device Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: Reading ALSA contributions from plugins. Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: MRS: Removed streaming files Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: MRS: volumioStreaming STOPPED Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: MRS: SNAPSERVER STOPPED Apr 10 13:36:42 volumio-skalisty volumio[1024]: info: MRS: SNAPCLIENT STOPPED Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:43 volumio-skalisty sudo[1737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 10 13:36:43 volumio-skalisty sudo[1737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPlay Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreStateMachine::play index undefined Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreStateMachine::startPlaybackTimer Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetVisibleSources Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: [1775821003643] ControllerWebradio::clearAddPlayTrack Apr 10 13:36:43 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand stop Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: sendMpdCommand stop took 27 milliseconds Apr 10 13:36:43 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand clear Apr 10 13:36:43 volumio-skalisty upmpdcli[1392]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: Apr 10 13:36:43 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: sendMpdCommand clear took 41 milliseconds Apr 10 13:36:43 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand load "https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach" Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: Apr 10 13:36:43 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: Apr 10 13:36:43 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:36:43 volumio-skalisty systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 10 13:36:43 volumio-skalisty systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 10 13:36:43 volumio-skalisty systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 10 13:36:43 volumio-skalisty volumio[1024]: error: updateQueue error: null Apr 10 13:36:43 volumio-skalisty sudo[1737]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:43 volumio-skalisty autossh[1743]: port set to 0, monitoring disabled Apr 10 13:36:43 volumio-skalisty autossh[1743]: starting ssh (count 1) Apr 10 13:36:43 volumio-skalisty autossh[1743]: ssh child pid is 1746 Apr 10 13:36:43 volumio-skalisty volumio[1024]: info: ------------------------------ 213ms Apr 10 13:36:44 volumio-skalisty volumio[1024]: info: Successfully Updated MyVolumio device Apr 10 13:36:44 volumio-skalisty volumio[1024]: info: Remote SSH Started Apr 10 13:36:45 volumio-skalisty volumiossh-tunnel[1746]: Warning: Permanently added '[eu9.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Successfully Updated MyVolumio device Apr 10 13:36:46 volumio-skalisty volumio[1024]: error: updateQueue error: null Apr 10 13:36:46 volumio-skalisty volumio[1024]: error: updateQueue error: null Apr 10 13:36:46 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand add "https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach" Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: ------------------------------ 2738ms Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: ------------------------------ 2736ms Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Apr 10 13:36:46 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: sendMpdCommand add "https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach" took 124 milliseconds Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 10 13:36:46 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand play Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Apr 10 13:36:46 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Apr 10 13:36:46 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:36:46 volumio-skalisty volumio[1024]: info: Asound.conf file written Apr 10 13:36:46 volumio-skalisty sudo[1751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 10 13:36:46 volumio-skalisty sudo[1751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:46 volumio-skalisty sudo[1751]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:47 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 10 13:36:47 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 10 13:36:47 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 10 13:36:47 volumio-skalisty volumio[1024]: No state is present for card sndrpihifiberry Apr 10 13:36:47 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 10 13:36:47 volumio-skalisty volumio[1024]: Found hardware: "RPi-simple" "" "" "" "" Apr 10 13:36:47 volumio-skalisty volumio[1024]: Hardware is initialized using a generic method Apr 10 13:36:47 volumio-skalisty volumio[1024]: No state is present for card sndrpihifiberry Apr 10 13:36:47 volumio-skalisty volumio[1024]: info: Output device has changed, restarting MPD Apr 10 13:36:47 volumio-skalisty volumio[1024]: info: Output device has changed, restarting Shairport Sync Apr 10 13:36:47 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:36:47 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:47 volumio-skalisty sudo[1757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 10 13:36:47 volumio-skalisty sudo[1757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:47 volumio-skalisty sudo[1757]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:47 volumio-skalisty sudo[1759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 10 13:36:47 volumio-skalisty sudo[1759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:47 volumio-skalisty systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:36:48 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 10 13:36:48 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: [FUNC] onStart Apr 10 13:36:48 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Apr 10 13:36:48 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Apr 10 13:36:48 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Apr 10 13:36:48 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output for this device Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: Adding audio output: Apr 10 13:36:48 volumio-skalisty volumio[1024]: info: Adding audio output: Apr 10 13:36:48 volumio-skalisty bluetoothd[783]: Path / reserved for Adv Monitor app :1.25 Apr 10 13:36:48 volumio-skalisty bluetoothd[783]: Adv Monitor app :1.25 disconnected from D-Bus Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Adding METAVOLUMIO REST API Endpoints Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Preparing CD Folders Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Adding CD REST API Endpoints Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Starting UDEV Watcher for CD Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: Detecting CD presence with UDEV Apr 10 13:36:49 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 10 13:36:52 volumio-skalisty systemd[1]: mpd.service: Deactivated successfully. Apr 10 13:36:52 volumio-skalisty systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 10 13:36:52 volumio-skalisty systemd[1]: mpd.service: Consumed 10.142s CPU time. Apr 10 13:36:52 volumio-skalisty systemd[1]: mpd.socket: Deactivated successfully. Apr 10 13:36:52 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection reset by peer Apr 10 13:36:52 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Apr 10 13:36:52 volumio-skalisty systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 10 13:36:52 volumio-skalisty systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 10 13:36:52 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:36:52 volumio-skalisty systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 10 13:36:52 volumio-skalisty systemd[1]: Starting mpd.service - Music Player Daemon... Apr 10 13:36:52 volumio-skalisty sudo[1796]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 10 13:36:52 volumio-skalisty sudo[1796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 10 13:36:52 volumio-skalisty sudo[1796]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:55 volumio-skalisty volumio[1024]: warn: [cd-plugin] cdspeedctl: device or media not ready Apr 10 13:36:55 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 10 13:36:55 volumio-skalisty volumio[1024]: info: Adding inputs REST Endpoints Apr 10 13:36:55 volumio-skalisty volumio[1024]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 10 13:36:55 volumio-skalisty volumio[1024]: info: Scanning Audio Inputs Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: Checking against Known Cards name Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: Adding Server instance for streaming Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 10 13:36:56 volumio-skalisty volumio[1024]: error: Hi Res Audio Failed Login: Missing Login Data Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Apr 10 13:36:56 volumio-skalisty volumio[1024]: info: QobuzConnect: Starting Qobuz Connect socket and service Apr 10 13:36:57 volumio-skalisty volumio[1024]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Apr 10 13:36:57 volumio-skalisty volumio[1024]: info: Adding TIDAL REST API Endpoints Apr 10 13:36:57 volumio-skalisty volumio[1024]: info: Stopping AccessToken refresher cron for QOBUZ Apr 10 13:36:57 volumio-skalisty sudo[1803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 10 13:36:57 volumio-skalisty sudo[1809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 10 13:36:57 volumio-skalisty sudo[1803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:57 volumio-skalisty sudo[1809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:58 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Apr 10 13:36:58 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Apr 10 13:36:58 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: AccessToken refresher cron started for QOBUZ Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: Adding QOBUZ REST API Endpoints Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: ------------------------------ 12264ms Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: sendMpdCommand play took 12218 milliseconds Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: ------------------------------ 12209ms Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: ------------------------------ 12202ms Apr 10 13:36:58 volumio-skalisty volumio[1024]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: MRS: Getting audio outputs on start Apr 10 13:36:58 volumio-skalisty volumio[1024]: info: MRS: Requesting all other devices output Apr 10 13:36:58 volumio-skalisty sudo[1803]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:58 volumio-skalisty volumio[1024]: error: MyVolumio Plugins failed to start in a timely fashion Apr 10 13:36:58 volumio-skalisty volumio[1024]: error: Plugin audio_interface bluetooth failed to complete 'onStart' in a timely fashion Apr 10 13:36:58 volumio-skalisty volumio[1024]: error: Plugin audio_interface multiroom failed to complete 'onStart' in a timely fashion Apr 10 13:36:58 volumio-skalisty volumio[1024]: error: Plugin music_service tidalconnect failed to complete 'onStart' in a timely fashion Apr 10 13:36:58 volumio-skalisty volumio[1024]: error: Plugin music_service qobuzconnect failed to complete 'onStart' in a timely fashion Apr 10 13:36:58 volumio-skalisty sudo[1809]: pam_unix(sudo:session): session closed for user root Apr 10 13:36:59 volumio-skalisty volumio[1024]: [Metrics] CommandRouter: 119s 960.81ms Apr 10 13:36:59 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumiosetStartupVolume Apr 10 13:36:59 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:36:59 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:36:59 volumio-skalisty volumio[1024]: info: CoreCommandRouter::Close All Modals sent Apr 10 13:36:59 volumio-skalisty volumio[1024]: info: CoreCommandRouter::Close All Modals sent Apr 10 13:36:59 volumio-skalisty sudo[1818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 10 13:36:59 volumio-skalisty sudo[1818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:36:59 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Apr 10 13:36:59 volumio-skalisty volumio[1024]: info: MPD Permissions set Apr 10 13:36:59 volumio-skalisty systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 10 13:36:59 volumio-skalisty sudo[1826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 10 13:36:59 volumio-skalisty sudo[1826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:00 volumio-skalisty sudo[1818]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:00 volumio-skalisty systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 10 13:37:00 volumio-skalisty sudo[1826]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:00 volumio-skalisty volumiobt[1837]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 10 13:37:00 volumio-skalisty sudo[1838]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 10 13:37:00 volumio-skalisty sudo[1838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:00 volumio-skalisty sudo[1838]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:00 volumio-skalisty sudo[1840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 10 13:37:00 volumio-skalisty sudo[1840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:00 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 10 13:37:00 volumio-skalisty sudo[1840]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:00 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 10 13:37:00 volumio-skalisty volumiobt[1842]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 10 13:37:00 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 10 13:37:00 volumio-skalisty volumiobt[1845]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 10 13:37:00 volumio-skalisty bluetoothd[783]: Adv Monitor app :1.27 disconnected from D-Bus Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [176B blob data] Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [157B blob data] Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [157B blob data] Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [157B blob data] Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [113B blob data] Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [bluetoothctl]> discoverable on Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [bluetoothctl]> pairable on Apr 10 13:37:00 volumio-skalisty volumiobt[1846]: [131B blob data] Apr 10 13:37:00 volumio-skalisty bluetoothd[783]: Path / reserved for Adv Monitor app :1.28 Apr 10 13:37:01 volumio-skalisty volumiobt[1846]: [bluetoothctl]> Apr 10 13:37:01 volumio-skalisty volumiobt[1847]: INFO [BTSTART] Registering Bluetooth agent... Apr 10 13:37:01 volumio-skalisty bluetoothd[783]: Adv Monitor app :1.28 disconnected from D-Bus Apr 10 13:37:01 volumio-skalisty volumiobt[1848]: [NEW] Media /org/bluez/hci0 Apr 10 13:37:01 volumio-skalisty volumiobt[1848]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 10 13:37:01 volumio-skalisty volumiobt[1848]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 10 13:37:01 volumio-skalisty volumiobt[1848]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Apr 10 13:37:01 volumio-skalisty bluetoothd[783]: Adv Monitor app :1.29 disconnected from D-Bus Apr 10 13:37:01 volumio-skalisty volumiobt[1849]: No agent is registered Apr 10 13:37:01 volumio-skalisty volumiobt[1849]: [NEW] Media /org/bluez/hci0 Apr 10 13:37:01 volumio-skalisty volumiobt[1849]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 10 13:37:01 volumio-skalisty volumiobt[1849]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 10 13:37:01 volumio-skalisty volumiobt[1849]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Apr 10 13:37:01 volumio-skalisty bluetoothd[783]: Path / reserved for Adv Monitor app :1.30 Apr 10 13:37:01 volumio-skalisty bluetoothd[783]: Adv Monitor app :1.30 disconnected from D-Bus Apr 10 13:37:01 volumio-skalisty volumiobt[1850]: INFO [BTSTART] Agent registered successfully. Apr 10 13:37:01 volumio-skalisty volumiobt[1851]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: Executing endpoint metavolumio Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 10 13:37:03 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Apr 10 13:37:03 volumio-skalisty volumio[1024]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:37:03 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:04 volumio-skalisty volumio[1024]: info: TidalConnect service stoped! Apr 10 13:37:04 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Apr 10 13:37:04 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Apr 10 13:37:04 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:37:04 volumio-skalisty volumio[1024]: info: Executing endpoint qc_getconfig Apr 10 13:37:04 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 10 13:37:04 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:04.929 [1828.1828] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 10 13:37:05 volumio-skalisty volumio[1024]: info: Starting Shairport Sync Apr 10 13:37:05 volumio-skalisty volumio[1024]: info: Preparing to generate the ALSA configuration file Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.388 [1828.1828] INFO VolumeManager: [0x119b068]: Setting new playback volume: 75 Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.388 [1828.1828] INFO VolumeManager: [0x119b068]: Setting new mute state: 0 Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.388 [1828.1828] INFO AudioStreamManager: [0x119adc0]: Setting new audio download buffer size: 1048576 Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.388 [1828.1828] INFO QobuzConnect: [0x119b930]: Client initialized! Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.388 [1828.1828] INFO SampleApp: Starting Avahi advertising, name: Volumio-Skalisty, service name: _qobuz-connect._tcp Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] Connecting to system D-Bus Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] Connected to system D-Bus Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 bluezutils [INFO] Found adapter at: /org/bluez/hci0 Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0 Apr 10 13:37:05 volumio-skalisty mpd[1798]: 2026-04-10T13:37:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.735 [1828.1828] INFO LocalConfigManager: [0x119aae8]: Starting Local Configuration server Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.735 [1828.1828] INFO SampleApp: Starting Local configuration server Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.735 [1828.1828] INFO SampleApp: Connected to UNIX socket client 0x1185818 Apr 10 13:37:05 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:05.736 [1828.1828] INFO SampleApp: Playback volume changed: 75 Apr 10 13:37:05 volumio-skalisty sudo[1870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 10 13:37:05 volumio-skalisty sudo[1870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] Set DiscoverableTimeout to infinite Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] Enabled Discoverable mode Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] Agent registered at /local/a2dpagent Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] Agent set as default Apr 10 13:37:05 volumio-skalisty volumiobt[1852]: 2026-04-10 13:37:05 a2dp-agent [INFO] A2DP agent running, waiting for connections... Apr 10 13:37:06 volumio-skalisty systemd[1]: Started mpd.service - Music Player Daemon. Apr 10 13:37:06 volumio-skalisty upmpdcli[1392]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Apr 10 13:37:06 volumio-skalisty sudo[1759]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:06 volumio-skalisty systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 10 13:37:06 volumio-skalisty systemd[1]: shairport-sync.service: Deactivated successfully. Apr 10 13:37:06 volumio-skalisty systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 10 13:37:06 volumio-skalisty systemd[1]: shairport-sync.service: Consumed 1.888s CPU time. Apr 10 13:37:06 volumio-skalisty systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 10 13:37:06 volumio-skalisty sudo[1870]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:07 volumio-skalisty volumio[1024]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 10 13:37:07 volumio-skalisty volumio[1024]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 10 13:37:07 volumio-skalisty volumio[1024]: info: BOOT COMPLETED Apr 10 13:37:07 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:07 volumio-skalisty volumio[1024]: info: Shairport-Sync Started Apr 10 13:37:07 volumio-skalisty volumio[1024]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 10 13:37:07 volumio-skalisty volumio[1024]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 10 13:37:10 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:11 volumio-skalisty volumio[1024]: error: updateQueue error: null Apr 10 13:37:11 volumio-skalisty volumio[1024]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.QsJr2Wk8IWfMO4zVsAVtDZeSdoH3.c8855b9f5aa2d55f707fb9f94858b4db.state.status' Apr 10 13:37:11 volumio-skalisty volumio[1024]: info: Asound.conf file written Apr 10 13:37:11 volumio-skalisty sudo[1914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 10 13:37:11 volumio-skalisty sudo[1914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:11 volumio-skalisty sudo[1910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 10 13:37:11 volumio-skalisty sudo[1910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:11 volumio-skalisty sudo[1914]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:11 volumio-skalisty systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 10 13:37:11 volumio-skalisty sudo[1910]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:11 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:37:11+02:00" level=trace msg="sent dealer ping" Apr 10 13:37:12 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:37:12+02:00" level=trace msg="received dealer pong" Apr 10 13:37:12 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 10 13:37:12 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 10 13:37:12 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 10 13:37:12 volumio-skalisty volumio[1024]: No state is present for card sndrpihifiberry Apr 10 13:37:12 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 10 13:37:12 volumio-skalisty volumio[1024]: Found hardware: "RPi-simple" "" "" "" "" Apr 10 13:37:12 volumio-skalisty volumio[1024]: Hardware is initialized using a generic method Apr 10 13:37:12 volumio-skalisty volumio[1024]: No state is present for card sndrpihifiberry Apr 10 13:37:12 volumio-skalisty volumio[1024]: info: Output device has changed, restarting MPD Apr 10 13:37:12 volumio-skalisty volumio[1024]: info: Output device has changed, restarting Shairport Sync Apr 10 13:37:12 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:12 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:37:12 volumio-skalisty sudo[1924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 10 13:37:12 volumio-skalisty sudo[1924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:12 volumio-skalisty sudo[1926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 10 13:37:12 volumio-skalisty sudo[1924]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:12 volumio-skalisty sudo[1926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:12 volumio-skalisty systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 10 13:37:12 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:37:12 volumio-skalisty volumio[1024]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 10 13:37:12 volumio-skalisty volumio[1024]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 10 13:37:12 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:13 volumio-skalisty volumio[1024]: info: QobuzConnect: setDeactiveState invoked Apr 10 13:37:13 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:13 volumio-skalisty volumio[1024]: info: Preparing to generate the ALSA configuration file Apr 10 13:37:13 volumio-skalisty sudo[1936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 10 13:37:13 volumio-skalisty sudo[1936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:13 volumio-skalisty systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Apr 10 13:37:13 volumio-skalisty systemd[1]: vtcs.service: Deactivated successfully. Apr 10 13:37:13 volumio-skalisty systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Apr 10 13:37:13 volumio-skalisty sudo[1936]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:14 volumio-skalisty sudo[1940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 10 13:37:14 volumio-skalisty sudo[1946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 10 13:37:14 volumio-skalisty sudo[1946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:14 volumio-skalisty sudo[1940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: Reading ALSA contributions from plugins. Apr 10 13:37:15 volumio-skalisty sudo[1946]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPlay Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreStateMachine::play index undefined Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreStateMachine::startPlaybackTimer Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetVisibleSources Apr 10 13:37:15 volumio-skalisty sudo[1940]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 10 13:37:15 volumio-skalisty sudo[1949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 10 13:37:15 volumio-skalisty sudo[1949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:15 volumio-skalisty volumio[1024]: info: [1775821035926] ControllerWebradio::clearAddPlayTrack Apr 10 13:37:15 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand stop Apr 10 13:37:15 volumio-skalisty systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 10 13:37:16 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:16.001 [1828.1828] INFO SampleApp: Stopping Local configuration server Apr 10 13:37:16 volumio-skalisty systemd[1]: mpd.service: Deactivated successfully. Apr 10 13:37:16 volumio-skalisty systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 10 13:37:16 volumio-skalisty systemd[1]: mpd.service: Consumed 7.239s CPU time. Apr 10 13:37:16 volumio-skalisty systemd[1]: mpd.socket: Deactivated successfully. Apr 10 13:37:16 volumio-skalisty systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 10 13:37:16 volumio-skalisty systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 10 13:37:16 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection refused Apr 10 13:37:16 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Apr 10 13:37:16 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:37:16 volumio-skalisty systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 10 13:37:16 volumio-skalisty systemd[1]: Starting mpd.service - Music Player Daemon... Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: MPD Permissions set Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: TidalConnect service started! Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: Executing endpoint tc_getconfig Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty sudo[1953]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 10 13:37:16 volumio-skalisty sudo[1953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 10 13:37:16 volumio-skalisty sudo[1953]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: TidalConnect service stoped! Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: Starting Shairport Sync Apr 10 13:37:16 volumio-skalisty sudo[1965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 10 13:37:16 volumio-skalisty volumio[1024]: info: Asound.conf file written Apr 10 13:37:17 volumio-skalisty sudo[1965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:17 volumio-skalisty systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 10 13:37:17 volumio-skalisty systemd[1]: shairport-sync.service: Deactivated successfully. Apr 10 13:37:17 volumio-skalisty systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 10 13:37:17 volumio-skalisty systemd[1]: shairport-sync.service: Consumed 1.357s CPU time. Apr 10 13:37:17 volumio-skalisty systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 10 13:37:17 volumio-skalisty sudo[1965]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:17 volumio-skalisty sudo[1970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 10 13:37:17 volumio-skalisty sudo[1970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:17 volumio-skalisty sudo[1970]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:17 volumio-skalisty qobuz-connect[1828]: 20260410 13:37:17.751 [1828.1828] INFO SampleApp: shat down connection on UNIX socket Apr 10 13:37:17 volumio-skalisty systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 10 13:37:17 volumio-skalisty systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 10 13:37:17 volumio-skalisty systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 10 13:37:17 volumio-skalisty sudo[1949]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:18 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 10 13:37:18 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 10 13:37:18 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 10 13:37:18 volumio-skalisty volumio[1024]: No state is present for card sndrpihifiberry Apr 10 13:37:18 volumio-skalisty volumio[1024]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 10 13:37:18 volumio-skalisty volumio[1024]: Found hardware: "RPi-simple" "" "" "" "" Apr 10 13:37:18 volumio-skalisty volumio[1024]: Hardware is initialized using a generic method Apr 10 13:37:18 volumio-skalisty volumio[1024]: No state is present for card sndrpihifiberry Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: Output device has changed, restarting MPD Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: Output device has changed, restarting Shairport Sync Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:37:18 volumio-skalisty sudo[1992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 10 13:37:18 volumio-skalisty sudo[1992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:18 volumio-skalisty sudo[1994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:18 volumio-skalisty sudo[1994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: QobuzConnect: setDeactiveState invoked Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:18 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:18 volumio-skalisty sudo[1992]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:18 volumio-skalisty sudo[2004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 10 13:37:18 volumio-skalisty sudo[2004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:18 volumio-skalisty systemd[1]: mpd.service: Deactivated successfully. Apr 10 13:37:18 volumio-skalisty systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 10 13:37:18 volumio-skalisty systemd[1]: mpd.service: Consumed 1.133s CPU time. Apr 10 13:37:18 volumio-skalisty systemd[1]: mpd.socket: Deactivated successfully. Apr 10 13:37:18 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection refused Apr 10 13:37:18 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Apr 10 13:37:18 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:37:18 volumio-skalisty systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 10 13:37:18 volumio-skalisty systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 10 13:37:19 volumio-skalisty systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 10 13:37:19 volumio-skalisty systemd[1]: Starting mpd.service - Music Player Daemon... Apr 10 13:37:19 volumio-skalisty sudo[2004]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:19 volumio-skalisty sudo[2007]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 10 13:37:19 volumio-skalisty sudo[2007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 10 13:37:19 volumio-skalisty sudo[2009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 10 13:37:19 volumio-skalisty sudo[2009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:19 volumio-skalisty sudo[2007]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:19 volumio-skalisty sudo[2009]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:19 volumio-skalisty sudo[2019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 10 13:37:19 volumio-skalisty sudo[2019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:19 volumio-skalisty volumio[1024]: info: MPD Permissions set Apr 10 13:37:19 volumio-skalisty volumio[1024]: info: TidalConnect service stoped! Apr 10 13:37:19 volumio-skalisty volumio[1024]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Apr 10 13:37:19 volumio-skalisty volumio[1024]: info: QobuzConnect: setDeactiveState invoked Apr 10 13:37:19 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:19 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:19 volumio-skalisty volumio[1024]: info: Shairport-Sync Started Apr 10 13:37:20 volumio-skalisty volumio[1024]: info: Executing endpoint qc_getconfig Apr 10 13:37:20 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 10 13:37:20 volumio-skalisty sudo[2019]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:20 volumio-skalisty sudo[2027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 10 13:37:20 volumio-skalisty sudo[2027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:20 volumio-skalisty systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 10 13:37:20 volumio-skalisty systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 10 13:37:20 volumio-skalisty systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 10 13:37:20 volumio-skalisty systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 10 13:37:20 volumio-skalisty sudo[2027]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 10 13:37:21 volumio-skalisty volumio[1024]: info: Executing endpoint qc_getconfig Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.221 [2031.2031] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.228 [2031.2031] INFO VolumeManager: [0x2379068]: Setting new playback volume: 75 Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.228 [2031.2031] INFO VolumeManager: [0x2379068]: Setting new mute state: 0 Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.228 [2031.2031] INFO AudioStreamManager: [0x2378dc0]: Setting new audio download buffer size: 1048576 Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.228 [2031.2031] INFO QobuzConnect: [0x2379930]: Client initialized! Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.228 [2031.2031] INFO SampleApp: Starting Avahi advertising, name: Volumio-Skalisty, service name: _qobuz-connect._tcp Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.282 [2031.2031] INFO LocalConfigManager: [0x2378ae8]: Starting Local Configuration server Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.282 [2031.2031] INFO SampleApp: Starting Local configuration server Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.283 [2031.2031] INFO SampleApp: Connected to UNIX socket client 0x2363818 Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: TidalConnect service stoped! Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: Starting Shairport Sync Apr 10 13:37:22 volumio-skalisty qobuz-connect[2031]: 20260410 13:37:22.380 [2031.2031] INFO SampleApp: Playback volume changed: 75 Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:22 volumio-skalisty sudo[2068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 10 13:37:22 volumio-skalisty sudo[2068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:22 volumio-skalisty sudo[2066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 10 13:37:22 volumio-skalisty sudo[2066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:22 volumio-skalisty volumio[1024]: info: TidalConnect service stoped! Apr 10 13:37:23 volumio-skalisty systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 10 13:37:23 volumio-skalisty sudo[2068]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:23 volumio-skalisty systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 10 13:37:23 volumio-skalisty systemd[1]: shairport-sync.service: Deactivated successfully. Apr 10 13:37:23 volumio-skalisty systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 10 13:37:23 volumio-skalisty systemd[1]: shairport-sync.service: Consumed 1.060s CPU time. Apr 10 13:37:23 volumio-skalisty systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 10 13:37:23 volumio-skalisty sudo[2066]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:23 volumio-skalisty volumio[1024]: info: Shairport-Sync Started Apr 10 13:37:23 volumio-skalisty mpd[2017]: 2026-04-10T13:37:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 10 13:37:23 volumio-skalisty volumio[1024]: info: Executing endpoint tc_getconfig Apr 10 13:37:23 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 10 13:37:23 volumio-skalisty upmpdcli[1392]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Apr 10 13:37:23 volumio-skalisty systemd[1]: Started mpd.service - Music Player Daemon. Apr 10 13:37:23 volumio-skalisty sudo[1994]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:23 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Apr 10 13:37:23 volumio-skalisty sudo[1926]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:23 volumio-skalisty volumio[1024]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 10 13:37:23 volumio-skalisty volumio[1024]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 10 13:37:23 volumio-skalisty vtcs[2076]: STARTING TidalConnect services, version: 1.6.1 Apr 10 13:37:23 volumio-skalisty vtcs[2076]: [2026-04-10 13:37:23.629] [tisoc] [critical] [DeviceInfo.cpp:52] ioctl error. ret=-1, errno="No such device" Apr 10 13:37:23 volumio-skalisty vtcs[2076]: [2026-04-10 13:37:23.629] [tisoc] [critical] [DeviceInfo.cpp:53] [ASSERT] generateDeviceId(0) Apr 10 13:37:23 volumio-skalisty vtcs[2076]: STARTED TidalConnect services. Apr 10 13:37:24 volumio-skalisty volumio[1024]: error: MPD error: The expression evaluated to a falsy value: Apr 10 13:37:24 volumio-skalisty volumio[1024]: assert.ok(self.idling) Apr 10 13:37:24 volumio-skalisty volumio[1024]: error: The expression evaluated to a falsy value: Apr 10 13:37:24 volumio-skalisty volumio[1024]: assert.ok(self.idling) Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: Executing endpoint tc_connect Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: Connecting to TidalConnect Apr 10 13:37:24 volumio-skalisty volumio[1024]: error: updateQueue error: null Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:24 volumio-skalisty sudo[2106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 10 13:37:24 volumio-skalisty sudo[2106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:24 volumio-skalisty sudo[2106]: pam_unix(sudo:session): session closed for user root Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:24 volumio-skalisty volumio[1024]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Apr 10 13:37:26 volumio-skalisty volumio[1024]: info: TidalConnect service started! Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPlay Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreStateMachine::play index undefined Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreStateMachine::startPlaybackTimer Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetVisibleSources Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: [1775821047420] ControllerWebradio::clearAddPlayTrack Apr 10 13:37:27 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand stop Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: sendMpdCommand stop took 2 milliseconds Apr 10 13:37:27 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand clear Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: Apr 10 13:37:27 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: sendMpdCommand clear took 21 milliseconds Apr 10 13:37:27 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand load "https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach" Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: Apr 10 13:37:27 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:37:27 volumio-skalisty volumio[1024]: error: updateQueue error: null Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: ------------------------------ 51ms Apr 10 13:37:27 volumio-skalisty volumio[1024]: info: TidalConnect service started! Apr 10 13:37:28 volumio-skalisty volumio[1024]: info: Executing endpoint metavolumio Apr 10 13:37:28 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 10 13:37:29 volumio-skalisty upmpdcli[1392]: :2:../src/mpdcli.cxx:336::MPDCli::getQueueSongs: mpd_list_queue_meta:finish failed: Timeout Apr 10 13:37:30 volumio-skalisty upmpdcli[1392]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Apr 10 13:37:30 volumio-skalisty upmpdcli[1392]: :2:../src/ohplaylist.cxx:206::OHPlaylist::makeIdArray: getQueueData failed.metacache size 1 Apr 10 13:37:30 volumio-skalisty volumio[1024]: error: updateQueue error: null Apr 10 13:37:30 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand add "https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach" Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: ------------------------------ 3281ms Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: Apr 10 13:37:30 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: sendMpdCommand add "https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach" took 3 milliseconds Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 10 13:37:30 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand play Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: Apr 10 13:37:30 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: ------------------------------ 45ms Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: sendMpdCommand play took 44 milliseconds Apr 10 13:37:30 volumio-skalisty volumio[1024]: info: ------------------------------ 43ms Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces state update: player Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::getState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand status Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces state update: player Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::getState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand status Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: sendMpdCommand status took 19 milliseconds Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces state update: player Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::getState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand status Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: sendMpdCommand status took 45 milliseconds Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces state update: player Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::getState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand status Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces state update: player Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Apr 10 13:37:32 volumio-skalisty volumio[1024]: ---------------------------- MPD announces state update: player Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: sendMpdCommand playlistinfo took 87 milliseconds Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: sendMpdCommand status took 70 milliseconds Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::getState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand status Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: sendMpdCommand playlistinfo took 70 milliseconds Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::getState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand status Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: sendMpdCommand status took 63 milliseconds Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseTrackInfo Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseTrackInfo Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseState Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::pushState Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream-128kmp3-BuddhaBeach","artist":null,"album":null,"uri":"https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach","trackType":""} Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: CURRENT POSITION 0 Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState stateService play Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState currentStatus stop Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: ControllerMpd::pushState Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Florzinho Euphonic Traveller - Like the First Moment","artist":"Vip-Radios.FM - Buddha Beach","album":null,"uri":"https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach","trackType":""} Apr 10 13:37:32 volumio-skalisty volumio[1024]: verbose: CURRENT POSITION 0 Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState stateService play Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState currentStatus play Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: Received an update from plugin. extracting info from payload Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 13:37:32 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ------------------------------ 660ms Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ------------------------------ 738ms Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: Apr 10 13:37:33 volumio-skalisty volumio[1024]: ---------------------------- MPD announces system playlist update Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: Ignoring MPD Status Update Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: Apr 10 13:37:33 volumio-skalisty volumio[1024]: ---------------------------- MPD announces state update: player Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ControllerMpd::getState Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand status Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ------------------------------ 652ms Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: sendMpdCommand status took 592 milliseconds Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ------------------------------ 652ms Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: sendMpdCommand status took 601 milliseconds Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: sendMpdCommand playlistinfo took 552 milliseconds Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: sendMpdCommand playlistinfo took 540 milliseconds Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ------------------------------ 28ms Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: sendMpdCommand status took 22 milliseconds Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseState Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseState Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseTrackInfo Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseTrackInfo Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseState Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ControllerMpd::pushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Florzinho Euphonic Traveller - Like the First Moment","artist":"Vip-Radios.FM - Buddha Beach","album":null,"uri":"https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach","trackType":""} Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: CURRENT POSITION 0 Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState stateService play Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState currentStatus play Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: Received an update from plugin. extracting info from payload Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ControllerMpd::pushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1106,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Florzinho Euphonic Traveller - Like the First Moment","artist":"Vip-Radios.FM - Buddha Beach","album":null,"uri":"https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach","trackType":""} Apr 10 13:37:33 volumio-skalisty volumio[1024]: verbose: CURRENT POSITION 0 Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState stateService play Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState currentStatus play Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: Received an update from plugin. extracting info from payload Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ------------------------------ 1274ms Apr 10 13:37:33 volumio-skalisty volumio[1024]: info: ------------------------------ 1224ms Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: sendMpdCommand playlistinfo took 1252 milliseconds Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: sendMpdCommand playlistinfo took 1251 milliseconds Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: sendMpdCommand playlistinfo took 1251 milliseconds Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseTrackInfo Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseTrackInfo Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: ControllerMpd::parseTrackInfo Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: ControllerMpd::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1483,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Florzinho Euphonic Traveller - Like the First Moment","artist":"Vip-Radios.FM - Buddha Beach","album":null,"uri":"https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach","trackType":""} Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: CURRENT POSITION 0 Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState stateService play Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState currentStatus play Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: Received an update from plugin. extracting info from payload Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: ControllerMpd::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1483,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Florzinho Euphonic Traveller - Like the First Moment","artist":"Vip-Radios.FM - Buddha Beach","album":null,"uri":"https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach","trackType":""} Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: CURRENT POSITION 0 Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState stateService play Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState currentStatus play Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: Received an update from plugin. extracting info from payload Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: ControllerMpd::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::servicePushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CorePlayQueue::getTrack 0 Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2102,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Florzinho Euphonic Traveller - Like the First Moment","artist":"Vip-Radios.FM - Buddha Beach","album":null,"uri":"https://radio4.vip-radios.fm:18054/stream-128kmp3-BuddhaBeach","trackType":""} Apr 10 13:37:34 volumio-skalisty volumio[1024]: verbose: CURRENT POSITION 0 Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState stateService play Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::syncState currentStatus play Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: Received an update from plugin. extracting info from payload Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreStateMachine::pushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioPushState Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output update for this device Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: MRS: Pushing multiroomSync output Apr 10 13:37:34 volumio-skalisty volumio[1024]: info: CoreCommandRouter::volumioGetState Apr 10 13:37:35 volumio-skalisty volumio[1024]: info: ------------------------------ 3015ms Apr 10 13:37:35 volumio-skalisty volumio[1024]: info: ------------------------------ 3006ms Apr 10 13:37:35 volumio-skalisty volumio[1024]: info: ------------------------------ 2380ms Apr 10 13:37:36 volumio-skalisty volumio[1024]: error: Failed request for metavolumio API Apr 10 13:37:36 volumio-skalisty volumio[1024]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 13:37:37 volumio-skalisty volumio[1024]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Apr 10 13:37:37 volumio-skalisty volumio[1024]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Apr 10 13:37:37 volumio-skalisty volumio[1024]: at new NodeError (node:internal/errors:405:5) Apr 10 13:37:37 volumio-skalisty volumio[1024]: at assert (node:internal/assert:14:11) Apr 10 13:37:37 volumio-skalisty volumio[1024]: at internalConnectMultiple (node:net:1118:3) Apr 10 13:37:37 volumio-skalisty volumio[1024]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Apr 10 13:37:37 volumio-skalisty volumio[1024]: at listOnTimeout (node:internal/timers:575:11) Apr 10 13:37:37 volumio-skalisty volumio[1024]: at process.processTimers (node:internal/timers:514:7) { Apr 10 13:37:37 volumio-skalisty volumio[1024]: code: 'ERR_INTERNAL_ASSERTION' Apr 10 13:37:37 volumio-skalisty volumio[1024]: } Apr 10 13:37:37 volumio-skalisty volumio[1024]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 13:37:40 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:37:40+02:00" level=trace msg="received accesspoint ping" Apr 10 13:37:41 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:37:41+02:00" level=trace msg="received accesspoint pong ack" Apr 10 13:37:41 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:37:41+02:00" level=trace msg="sent dealer ping" Apr 10 13:37:41 volumio-skalisty go-librespot[1463]: time="2026-04-10T13:37:41+02:00" level=trace msg="received dealer pong" Apr 10 13:37:48 volumio-skalisty sudo[2169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-10 13:36' Apr 10 13:37:48 volumio-skalisty sudo[2169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"