Jun 24 20:51:06 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:06 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:06 volpi4-beta volumio[1409]: info: Listing playlists Jun 24 20:51:06 volpi4-beta volumio[1409]: info: Listing playlists Jun 24 20:51:07 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jun 24 20:51:07 volpi4-beta volumio[1409]: info: handleBrowseUri took 138 milliseconds Jun 24 20:51:07 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:07 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:16 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:16 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:25 volpi4-beta systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 24 20:51:25 volpi4-beta dbus-daemon[702]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.496' (uid=0 pid=1103 comm="timedatectl show --property=NTPSynchronized --valu") Jun 24 20:51:25 volpi4-beta systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 24 20:51:25 volpi4-beta dbus-daemon[702]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 24 20:51:25 volpi4-beta systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 24 20:51:25 volpi4-beta setdatetime-helper.sh[1102]: Time is already synchronized. Jun 24 20:51:25 volpi4-beta systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 24 20:51:25 volpi4-beta systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 24 20:51:26 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:26 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:26 volpi4-beta volumio[1409]: info: Listing playlists Jun 24 20:51:26 volpi4-beta volumio[1409]: info: Listing playlists Jun 24 20:51:31 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetQueue Jun 24 20:51:31 volpi4-beta volumio[1409]: info: CoreStateMachine::getQueue Jun 24 20:51:31 volpi4-beta volumio[1409]: info: CorePlayQueue::getQueue Jun 24 20:51:33 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jun 24 20:51:33 volpi4-beta volumio[1409]: info: handleBrowseUri took 152 milliseconds Jun 24 20:51:33 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:33 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:36 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jun 24 20:51:36 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:36 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:38 volpi4-beta volumio[1409]: info: handleBrowseUri took 2860 milliseconds Jun 24 20:51:38 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:46 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:46 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:46 volpi4-beta volumio[1409]: info: Listing playlists Jun 24 20:51:46 volpi4-beta volumio[1409]: info: Listing playlists Jun 24 20:51:47 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: handleBrowseUri took 650 milliseconds Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/46068270 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/11614808 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/51892971 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/114057419 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/47683476 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/28187772 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/104018007 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/32848609 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/118923698 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/4255383 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/2940335 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/79198116 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/16034065 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/25311776 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/120013594 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/103317960 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/72879753 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/335060286 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/79557470 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/61197986 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/6419041 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/3175224 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/50997507 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/124937990 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/130617563 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/47588658 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/11630583 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/17890424 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Preloading song: qobuz://song/49380 Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/46068270 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/11614808 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/51892971 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/114057419 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/47683476 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/28187772 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/104018007 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: explodeUri took 350 milliseconds Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/32848609 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/118923698 in service qobuz Jun 24 20:51:48 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:48 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/4255383 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/2940335 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 493 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/79198116 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 486 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 447 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/16034065 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/25311776 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 347 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/120013594 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 518 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 468 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/103317960 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/72879753 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 409 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/335060286 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 579 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/79557470 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 441 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 493 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/61197986 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 412 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 384 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/6419041 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 373 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/3175224 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 389 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/50997507 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 358 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 338 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/124937990 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/130617563 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 364 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/47588658 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 369 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/11630583 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 339 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/17890424 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 412 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: Exploding uri qobuz://song/49380 in service qobuz Jun 24 20:51:49 volpi4-beta volumio[1409]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 373 milliseconds Jun 24 20:51:49 volpi4-beta volumio[1409]: info: explodeUri took 335 milliseconds Jun 24 20:51:50 volpi4-beta volumio[1409]: info: explodeUri took 377 milliseconds Jun 24 20:51:50 volpi4-beta volumio[1409]: info: explodeUri took 356 milliseconds Jun 24 20:51:50 volpi4-beta volumio[1409]: info: explodeUri took 335 milliseconds Jun 24 20:51:50 volpi4-beta volumio[1409]: info: explodeUri took 376 milliseconds Jun 24 20:51:50 volpi4-beta volumio[1409]: info: explodeUri took 341 milliseconds Jun 24 20:51:50 volpi4-beta volumio[1409]: info: explodeUri took 316 milliseconds Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::ClearQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::stop Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::updateTrackBlock Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrackBlock Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::stPlaybackTimer Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::pushState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPushState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output update for this device Jun 24 20:51:55 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::serviceStop Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 3 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::serviceStop Jun 24 20:51:55 volpi4-beta volumio[1409]: info: ControllerMpd::stop Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand stop Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::clearPlayQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::saveQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPushQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::addQueueItems Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::addQueueItems Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/46068270 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/46068270 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPushQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::saveQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::updateTrackBlock Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrackBlock Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPlay Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::play index 0 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::addQueueItems Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::addQueueItems Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Preload queue cleared Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/11614808 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/11614808 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/51892971 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/51892971 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/114057419 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/114057419 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/47683476 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/47683476 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/28187772 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/28187772 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/104018007 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/104018007 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/32848609 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/32848609 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/118923698 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/118923698 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/4255383 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/4255383 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/2940335 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/2940335 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/79198116 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/79198116 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/16034065 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/16034065 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/25311776 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/25311776 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/120013594 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/120013594 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/103317960 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/103317960 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/72879753 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/72879753 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/335060286 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/335060286 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/79557470 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/79557470 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/61197986 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/61197986 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/6419041 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/6419041 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/3175224 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/3175224 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/50997507 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/50997507 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/124937990 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/124937990 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/130617563 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/130617563 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/47588658 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/47588658 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/11630583 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/11630583 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/17890424 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/17890424 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Adding Item to queue: qobuz://song/49380 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Using cached record of: qobuz://song/49380 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::stop Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPushQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::saveQueue Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::play index undefined Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::updateTrackBlock Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrackBlock Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 0 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::startPlaybackTimer Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 0 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: [1750794715282] ControllerQobuz::clearAddPlayTrack Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Jun 24 20:51:55 volpi4-beta volumio[1409]: ---------------------------- MPD announces state update: player Jun 24 20:51:55 volpi4-beta volumio[1409]: info: sendMpdCommand stop took 69 milliseconds Jun 24 20:51:55 volpi4-beta volumio[1409]: info: ControllerMpd::getState Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand status Jun 24 20:51:55 volpi4-beta volumio[1409]: info: sendMpdCommand status took 3 milliseconds Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::parseState Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 20:51:55 volpi4-beta volumio[1409]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::parseTrackInfo Jun 24 20:51:55 volpi4-beta volumio[1409]: info: ControllerMpd::pushState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::servicePushState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreStateMachine::pushState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 0 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPushState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output update for this device Jun 24 20:51:55 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 0 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 0 Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 24 20:51:55 volpi4-beta volumio[1409]: info: ------------------------------ 21ms Jun 24 20:51:55 volpi4-beta volumio[1409]: info: getStreamUrl took 280 milliseconds Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand stop Jun 24 20:51:55 volpi4-beta volumio[1409]: info: sendMpdCommand stop took 1 milliseconds Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand clear Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Jun 24 20:51:55 volpi4-beta volumio[1409]: ---------------------------- MPD announces system playlist update Jun 24 20:51:55 volpi4-beta volumio[1409]: info: Ignoring MPD Status Update Jun 24 20:51:55 volpi4-beta volumio[1409]: info: sendMpdCommand clear took 1 milliseconds Jun 24 20:51:55 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=5311640&eid=46068270&fmt=6&profile=raw&app_id=539451548&cid=2848225&etsp=1750798315&hmac=XEcLe8y85rUhhdlFNjipQc74otI" Jun 24 20:51:55 volpi4-beta volumio[1409]: error: updateQueue error: null Jun 24 20:51:55 volpi4-beta volumio[1409]: info: ------------------------------ 2ms Jun 24 20:51:55 volpi4-beta systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=5311640&eid=46068270&fmt=6&profile=raw&app_id=539451548&cid=2848225&etsp=1750798315&hmac=XEcLe8y85rUhhdlFNjipQc74otI" Jun 24 20:51:56 volpi4-beta volumio[1409]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=5311640&eid=46068270&fmt=6&profile=raw&app_id=539451548&cid=2848225&etsp=1750798315&hmac=XEcLe8y85rUhhdlFNjipQc74otI" took 1 milliseconds Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand play Jun 24 20:51:56 volpi4-beta volumio[1409]: info: Jun 24 20:51:56 volpi4-beta volumio[1409]: ---------------------------- MPD announces system playlist update Jun 24 20:51:56 volpi4-beta volumio[1409]: info: Ignoring MPD Status Update Jun 24 20:51:56 volpi4-beta volumio[1409]: info: sendMpdCommand play took 1 milliseconds Jun 24 20:51:56 volpi4-beta volumio[1409]: info: ------------------------------ 2ms Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: Jun 24 20:51:56 volpi4-beta volumio[1409]: ---------------------------- MPD announces state update: player Jun 24 20:51:56 volpi4-beta volumio[1409]: info: ControllerMpd::getState Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand status Jun 24 20:51:56 volpi4-beta volumio[1409]: info: FusionDsp - ---- read samplerate, raw: 384000,S32_LE,2,32 Jun 24 20:51:56 volpi4-beta volumio[1409]: info: FusionDsp - ---- read samplerate from file: 384000 Jun 24 20:51:56 volpi4-beta volumio[1409]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 24 20:51:56 volpi4-beta volumio[1409]: info: Jun 24 20:51:56 volpi4-beta volumio[1409]: ---------------------------- MPD announces state update: player Jun 24 20:51:56 volpi4-beta volumio[1409]: info: sendMpdCommand status took 22 milliseconds Jun 24 20:51:56 volpi4-beta volumio[1409]: info: ControllerMpd::getState Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand status Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::parseState Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 20:51:56 volpi4-beta volumio[1409]: info: sendMpdCommand status took 3 milliseconds Jun 24 20:51:56 volpi4-beta volumio[1409]: info: sendMpdCommand playlistinfo took 7 milliseconds Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::parseState Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::parseTrackInfo Jun 24 20:51:56 volpi4-beta volumio[1409]: info: ControllerMpd::pushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::servicePushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 0 Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=5311640&eid=46068270&fmt=6&profile=raw&app_id=539451548&cid=2848225&etsp=1750798315&hmac=XEcLe8y85rUhhdlFNjipQc74otI","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=5311640&eid=46068270&fmt=6&profile=raw&app_id=539451548&cid=2848225&etsp=1750798315&hmac=XEcLe8y85rUhhdlFNjipQc74otI","trackType":"qobuz"} Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: CURRENT POSITION 0 Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreStateMachine::syncState stateService play Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreStateMachine::syncState currentStatus stop Jun 24 20:51:56 volpi4-beta volumio[1409]: info: ------------------------------ 42ms Jun 24 20:51:56 volpi4-beta volumio[1409]: info: sendMpdCommand playlistinfo took 10 milliseconds Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: ControllerMpd::parseTrackInfo Jun 24 20:51:56 volpi4-beta volumio[1409]: info: ControllerMpd::pushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::servicePushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CorePlayQueue::getTrack 0 Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":191,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"731 Kbps","isStreaming":false,"title":"file?uid=5311640&eid=46068270&fmt=6&profile=raw&app_id=539451548&cid=2848225&etsp=1750798315&hmac=XEcLe8y85rUhhdlFNjipQc74otI","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=5311640&eid=46068270&fmt=6&profile=raw&app_id=539451548&cid=2848225&etsp=1750798315&hmac=XEcLe8y85rUhhdlFNjipQc74otI","trackType":"qobuz"} Jun 24 20:51:56 volpi4-beta volumio[1409]: verbose: CURRENT POSITION 0 Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreStateMachine::syncState stateService play Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreStateMachine::syncState currentStatus play Jun 24 20:51:56 volpi4-beta volumio[1409]: info: Received an update from plugin. extracting info from payload Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreStateMachine::pushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output update for this device Jun 24 20:51:56 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreStateMachine::pushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioPushState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output update for this device Jun 24 20:51:56 volpi4-beta volumio[1409]: info: MRS: Pushing multiroomSync output Jun 24 20:51:56 volpi4-beta volumio[1409]: info: CoreCommandRouter::volumioGetState Jun 24 20:51:56 volpi4-beta volumio[1409]: info: ------------------------------ 76ms Jun 24 20:51:57 volpi4-beta volumio[1409]: info: touch_display: Setting screensaver timeout to 0 seconds. Jun 24 20:52:05 volpi4-beta volumio[1409]: Searching all installed plugins Jun 24 20:52:05 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 20:52:05 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: , search Jun 24 20:52:05 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jun 24 20:52:05 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Jun 24 20:52:05 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Jun 24 20:52:05 volpi4-beta volumio[1409]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Jun 24 20:52:05 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: webradio , search Jun 24 20:52:05 volpi4-beta volumio[1409]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jun 24 20:52:05 volpi4-beta volumio[1409]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 20:52:05 volpi4-beta volumio[1409]: TypeError: Cannot read properties of undefined (reading 'length') Jun 24 20:52:05 volpi4-beta volumio[1409]: at /volumio/node_modules/libxmljs/dist/lib/parse.js:186:126 Jun 24 20:52:05 volpi4-beta volumio[1409]: at Object.parseXml (/volumio/node_modules/libxmljs/dist/lib/parse.js:185:49) Jun 24 20:52:05 volpi4-beta volumio[1409]: at /volumio/app/plugins/music_service/webradio/index.js:949:31 Jun 24 20:52:05 volpi4-beta volumio[1409]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 24 20:52:05 volpi4-beta volumio[1409]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 20:52:05 volpi4-beta sudo[1205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-24 20:51' Jun 24 20:52:05 volpi4-beta sudo[1205]: 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="cee9bb5b0ee50e4898478097a64b5c6c77d5a212" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="b0310d60a07948a2a8a2e8db322034758c86aad6" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 21 15:01:23 UTC 2025" VOLUMIO_VERSION="4.013" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6df2d5f0b86e6f2c0cd4dc68c66de48c"