-- Logs begin at Thu 2025-02-20 18:58:50 PST, end at Thu 2025-02-20 19:08:07 PST. -- Feb 20 19:07:00 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Feb 20 19:07:01 rivo volumio[3113]: info: handleBrowseUri took 1460 milliseconds Feb 20 19:07:02 rivo volumio[3113]: info: Preload queue cleared Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087907 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087908 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087909 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087910 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087911 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087912 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087913 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087914 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087915 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087916 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087917 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087918 Feb 20 19:07:02 rivo volumio[3113]: info: Preloading song: qobuz://song/32087919 Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087907 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087908 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087909 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Executing endpoint getSimilarAlbums Feb 20 19:07:02 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087910 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087911 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Executing endpoint metavolumio Feb 20 19:07:02 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 20 19:07:02 rivo volumio[3113]: info: Executing endpoint metavolumio Feb 20 19:07:02 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087912 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087913 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087914 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087915 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087916 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087917 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087918 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: Exploding uri qobuz://song/32087919 in service qobuz Feb 20 19:07:02 rivo volumio[3113]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 20 19:07:02 rivo volumio[3113]: info: explodeUri took 628 milliseconds Feb 20 19:07:02 rivo volumio[3113]: info: explodeUri took 685 milliseconds Feb 20 19:07:02 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 20 19:07:02 rivo volumio[3113]: info: explodeUri took 588 milliseconds Feb 20 19:07:02 rivo volumio[3113]: info: explodeUri took 676 milliseconds Feb 20 19:07:02 rivo volumio[3113]: info: explodeUri took 620 milliseconds Feb 20 19:07:02 rivo volumio[3113]: info: explodeUri took 615 milliseconds Feb 20 19:07:03 rivo volumio[3113]: info: explodeUri took 684 milliseconds Feb 20 19:07:03 rivo volumio[3113]: info: explodeUri took 641 milliseconds Feb 20 19:07:03 rivo volumio[3113]: info: explodeUri took 758 milliseconds Feb 20 19:07:03 rivo volumio[3113]: info: explodeUri took 758 milliseconds Feb 20 19:07:03 rivo volumio[3113]: info: explodeUri took 688 milliseconds Feb 20 19:07:03 rivo volumio[3113]: info: explodeUri took 760 milliseconds Feb 20 19:07:03 rivo volumio[3113]: info: explodeUri took 671 milliseconds Feb 20 19:07:11 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 20 19:07:11 rivo volumio[3113]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 20 19:07:11 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 20 19:07:11 rivo volumio[3113]: info: Received Get System Version Feb 20 19:07:11 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 19:07:11 rivo volumio[3113]: info: Received Get System Info Feb 20 19:07:11 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 19:07:11 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 19:07:11 rivo volumio[3113]: info: Discovery: Getting this device information Feb 20 19:07:11 rivo volumio[3113]: info: CoreCommandRouter::volumioGetState Feb 20 19:07:11 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 19:07:20 rivo volumio[3113]: info: Preload queue cleared Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::ClearQueue Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::stop Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::stPlaybackTimer Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::updateTrackBlock Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::getTrackBlock Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::getTrack 0 Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::serviceStop Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::getTrack 0 Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::serviceStop Feb 20 19:07:20 rivo volumio[3113]: info: [1740107240875] ControllerQobuz::stop Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 20 19:07:20 rivo volumio[3113]: info: ControllerMpd::stop Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand stop Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::clearPlayQueue Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::saveQueue Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::volumioPushQueue Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::addQueueItems Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::addQueueItems Feb 20 19:07:20 rivo volumio[3113]: info: Preload queue cleared Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087907 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087907 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087908 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087908 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087909 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087909 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087910 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087910 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087911 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087911 Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::volumioPushQueue Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::saveQueue Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::updateTrackBlock Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::getTrackBlock Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::volumioPlay Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::play index 4 Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::addQueueItems Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::addQueueItems Feb 20 19:07:20 rivo volumio[3113]: info: Preload queue cleared Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087912 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087912 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087913 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087913 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087914 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087914 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087915 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087915 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087916 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087916 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087917 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087917 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087918 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087918 Feb 20 19:07:20 rivo volumio[3113]: info: Adding Item to queue: qobuz://song/32087919 Feb 20 19:07:20 rivo volumio[3113]: info: Using cached record of: qobuz://song/32087919 Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::stop Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 19:07:20 rivo volumio[3113]: info: CoreCommandRouter::volumioPushQueue Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::saveQueue Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::play index undefined Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::updateTrackBlock Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::getTrackBlock Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:20 rivo volumio[3113]: info: CoreStateMachine::startPlaybackTimer Feb 20 19:07:20 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:20 rivo volumio[3113]: info: [1740107240952] ControllerQobuz::clearAddPlayTrack Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand stop Feb 20 19:07:20 rivo volumio[3113]: info: Feb 20 19:07:20 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:20 rivo volumio[3113]: info: sendMpdCommand stop took 97 milliseconds Feb 20 19:07:20 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:20 rivo volumio[3113]: info: sendMpdCommand stop took 21 milliseconds Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand clear Feb 20 19:07:20 rivo volumio[3113]: info: Feb 20 19:07:20 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:20 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:20 rivo volumio[3113]: info: Feb 20 19:07:20 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:20 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:20 rivo volumio[3113]: info: Feb 20 19:07:20 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:20 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:20 rivo volumio[3113]: info: Feb 20 19:07:20 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:20 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:20 rivo volumio[3113]: info: sendMpdCommand status took 17 milliseconds Feb 20 19:07:20 rivo volumio[3113]: info: sendMpdCommand clear took 17 milliseconds Feb 20 19:07:20 rivo volumio[3113]: info: sendMpdCommand status took 15 milliseconds Feb 20 19:07:20 rivo volumio[3113]: info: sendMpdCommand status took 11 milliseconds Feb 20 19:07:20 rivo volumio[3113]: info: sendMpdCommand status took 8 milliseconds Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/32087911" Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:20 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:21 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:21 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:21 rivo volumio[3113]: STREAMING PROXY: Handling url /?data=qobuz://song/32087911 Feb 20 19:07:21 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:21 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:21 rivo volumio[3113]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 20 19:07:21 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:21 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:21 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:21 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:21 rivo volumio[3113]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 20 19:07:21 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:21 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:21 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:21 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:21 rivo volumio[3113]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 20 19:07:21 rivo volumio[3113]: info: ------------------------------ 86ms Feb 20 19:07:21 rivo volumio[3113]: info: ------------------------------ 84ms Feb 20 19:07:21 rivo volumio[3113]: info: ------------------------------ 80ms Feb 20 19:07:21 rivo volumio[3113]: info: Feb 20 19:07:21 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:21 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:21 rivo volumio[3113]: info: Feb 20 19:07:21 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:21 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:21 rivo volumio[3113]: info: Feb 20 19:07:21 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:21 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:21 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:21 rivo volumio[3113]: info: ------------------------------ 91ms Feb 20 19:07:21 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 87 milliseconds Feb 20 19:07:21 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:21 rivo volumio[3113]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 20 19:07:21 rivo volumio[3113]: info: ------------------------------ 114ms Feb 20 19:07:21 rivo volumio[3113]: info: MCU Signalled Playback Inactive Feb 20 19:07:21 rivo volumio[3113]: info: Executing endpoint getStreamUrlqobuz Feb 20 19:07:21 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 20 19:07:21 rivo volumio[3113]: info: getStreamUrl took 579 milliseconds Feb 20 19:07:21 rivo volumio[3113]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2506689&eid=32087911&fmt=27&profile=raw&app_id=539451548&cid=1736740&etsp=1740110841&hmac=TiElCJJ7cKtl05gOtf4kTaOuNzY Feb 20 19:07:21 rivo volumio[3113]: info: camilladsp spawned new process with pid 6078, instance 1, run: true Feb 20 19:07:23 rivo volumio[3113]: STREAMING PROXY: Response: 200, length: 172882314 Feb 20 19:07:23 rivo volumio[3113]: STREAMING PROXY: Client dropped request, destroying Feb 20 19:07:23 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:23 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:23 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:23 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/32087911" Feb 20 19:07:23 rivo volumio[3113]: info: ------------------------------ 2477ms Feb 20 19:07:23 rivo volumio[3113]: info: ------------------------------ 2476ms Feb 20 19:07:23 rivo volumio[3113]: info: ------------------------------ 2476ms Feb 20 19:07:23 rivo volumio[3113]: Upnp client error: Error: This socket has been ended by the other party Feb 20 19:07:23 rivo volumio[3113]: info: Feb 20 19:07:23 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:23 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:23 rivo volumio[3113]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/32087911" took 9 milliseconds Feb 20 19:07:23 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 20 19:07:23 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand play Feb 20 19:07:23 rivo volumio[3113]: info: Feb 20 19:07:23 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:23 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:23 rivo volumio[3113]: STREAMING PROXY: Handling url /?data=qobuz://song/32087911 Feb 20 19:07:23 rivo volumio[3113]: info: Feb 20 19:07:23 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:23 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:23 rivo volumio[3113]: info: Feb 20 19:07:23 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:23 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:23 rivo volumio[3113]: info: ------------------------------ 19ms Feb 20 19:07:23 rivo volumio[3113]: info: sendMpdCommand play took 16 milliseconds Feb 20 19:07:23 rivo volumio[3113]: info: ------------------------------ 14ms Feb 20 19:07:23 rivo volumio[3113]: info: ------------------------------ 6ms Feb 20 19:07:23 rivo volumio[3113]: info: ------------------------------ 5ms Feb 20 19:07:23 rivo volumio[3113]: info: Executing endpoint getStreamUrlqobuz Feb 20 19:07:23 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 20 19:07:25 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 19:07:25 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 19:07:25 rivo volumio[3113]: info: Discovery: Getting this device information Feb 20 19:07:25 rivo volumio[3113]: info: CoreCommandRouter::volumioGetState Feb 20 19:07:25 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::volumioPlay Feb 20 19:07:33 rivo volumio[3113]: info: CoreStateMachine::play index undefined Feb 20 19:07:33 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: CoreStateMachine::startPlaybackTimer Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: [1740107253125] ControllerQobuz::clearAddPlayTrack Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand stop Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:33 rivo volumio[3113]: info: sendMpdCommand stop took 6 milliseconds Feb 20 19:07:33 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand clear Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:33 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:33 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:33 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:33 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:33 rivo volumio[3113]: info: sendMpdCommand status took 15 milliseconds Feb 20 19:07:33 rivo volumio[3113]: info: sendMpdCommand clear took 14 milliseconds Feb 20 19:07:33 rivo volumio[3113]: info: sendMpdCommand status took 11 milliseconds Feb 20 19:07:33 rivo volumio[3113]: info: sendMpdCommand status took 8 milliseconds Feb 20 19:07:33 rivo volumio[3113]: info: sendMpdCommand status took 5 milliseconds Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/32087911" Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:33 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:33 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:33 rivo volumio[3113]: STREAMING PROXY: Handling url /?data=qobuz://song/32087911 Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 20 19:07:33 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:33 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 20 19:07:33 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:33 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:33 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:33 rivo volumio[3113]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 20 19:07:33 rivo volumio[3113]: info: ------------------------------ 75ms Feb 20 19:07:33 rivo volumio[3113]: info: ------------------------------ 72ms Feb 20 19:07:33 rivo volumio[3113]: info: ------------------------------ 69ms Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:33 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:33 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:33 rivo volumio[3113]: info: Feb 20 19:07:33 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:33 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:33 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:33 rivo volumio[3113]: info: ------------------------------ 76ms Feb 20 19:07:33 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 73 milliseconds Feb 20 19:07:33 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:33 rivo volumio[3113]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 20 19:07:33 rivo volumio[3113]: info: ------------------------------ 96ms Feb 20 19:07:33 rivo volumio[3113]: info: Executing endpoint getStreamUrlqobuz Feb 20 19:07:33 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 20 19:07:33 rivo volumio[3113]: info: getStreamUrl took 10228 milliseconds Feb 20 19:07:33 rivo volumio[3113]: error: Could not get QOBUZ Stream URL: [object Object] Feb 20 19:07:33 rivo volumio[3113]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get QOBUZ Stream URL: [object Object]"} Feb 20 19:07:35 rivo volumio[3113]: info: getStreamUrl took 2740 milliseconds Feb 20 19:07:35 rivo volumio[3113]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2506689&eid=32087911&fmt=27&profile=raw&app_id=539451548&cid=1736740&etsp=1740110853&hmac=srk-4ZydRQ5XDHjVcV_EhwiVFs8 Feb 20 19:07:36 rivo volumio[3113]: STREAMING PROXY: Response: 200, length: 172882314 Feb 20 19:07:36 rivo volumio[3113]: STREAMING PROXY: Client dropped request, destroying Feb 20 19:07:36 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/32087911" Feb 20 19:07:36 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:36 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:36 rivo volumio[3113]: error: updateQueue error: null Feb 20 19:07:36 rivo volumio[3113]: info: ------------------------------ 2953ms Feb 20 19:07:36 rivo volumio[3113]: info: ------------------------------ 2952ms Feb 20 19:07:36 rivo volumio[3113]: info: ------------------------------ 2951ms Feb 20 19:07:36 rivo volumio[3113]: Upnp client error: Error: This socket has been ended by the other party Feb 20 19:07:36 rivo volumio[3113]: info: Feb 20 19:07:36 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:36 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:36 rivo volumio[3113]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/32087911" took 8 milliseconds Feb 20 19:07:36 rivo volumio[3113]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 20 19:07:36 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand play Feb 20 19:07:36 rivo volumio[3113]: info: Feb 20 19:07:36 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:36 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:36 rivo volumio[3113]: info: Feb 20 19:07:36 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:36 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:36 rivo volumio[3113]: STREAMING PROXY: Handling url /?data=qobuz://song/32087911 Feb 20 19:07:36 rivo volumio[3113]: info: Feb 20 19:07:36 rivo volumio[3113]: ---------------------------- MPD announces system playlist update Feb 20 19:07:36 rivo volumio[3113]: info: Ignoring MPD Status Update Feb 20 19:07:36 rivo volumio[3113]: info: ------------------------------ 10ms Feb 20 19:07:36 rivo volumio[3113]: info: sendMpdCommand play took 8 milliseconds Feb 20 19:07:36 rivo volumio[3113]: info: ------------------------------ 8ms Feb 20 19:07:36 rivo volumio[3113]: info: ------------------------------ 6ms Feb 20 19:07:36 rivo volumio[3113]: info: ------------------------------ 6ms Feb 20 19:07:36 rivo volumio[3113]: info: Executing endpoint getStreamUrlqobuz Feb 20 19:07:36 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 20 19:07:36 rivo volumio[3113]: info: getStreamUrl took 683 milliseconds Feb 20 19:07:36 rivo volumio[3113]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2506689&eid=32087911&fmt=27&profile=raw&app_id=539451548&cid=1736740&etsp=1740110856&hmac=1YtkPE0AUEY43eoYHTGNRi07H_I Feb 20 19:07:36 rivo volumio[3113]: STREAMING PROXY: Response: 200, length: 172882314 Feb 20 19:07:36 rivo volumio[3113]: info: Feb 20 19:07:36 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:36 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:36 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: Feb 20 19:07:37 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: Feb 20 19:07:37 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: Feb 20 19:07:37 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Feb 20 19:07:37 rivo volumio[3113]: info: FusionDsp - ---- read samplerate from file: 192000 Feb 20 19:07:37 rivo volumio[3113]: info: camilladsp stopping service pid 6078... Feb 20 19:07:37 rivo volumio[3113]: info: camilladsp service terminated, instance 1 Feb 20 19:07:37 rivo volumio[3113]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 20 19:07:37 rivo volumio[3113]: info: camilladsp service started and running in background, instance 1 Feb 20 19:07:37 rivo volumio[3113]: info: Feb 20 19:07:37 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: Feb 20 19:07:37 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: Feb 20 19:07:37 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: Feb 20 19:07:37 rivo volumio[3113]: ---------------------------- MPD announces state update: player Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 95 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::getState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand status Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 87 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 79 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 76 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 17 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 12 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 9 milliseconds Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand status took 22 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 18 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 15 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 15 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 12 milliseconds Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseState Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus stop Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus play Feb 20 19:07:37 rivo volumio[3113]: info: Received an update from plugin. extracting info from payload Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus play Feb 20 19:07:37 rivo volumio[3113]: info: Received an update from plugin. extracting info from payload Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus play Feb 20 19:07:37 rivo volumio[3113]: info: Received an update from plugin. extracting info from payload Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":506,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5193 Kbps","isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus play Feb 20 19:07:37 rivo volumio[3113]: info: Received an update from plugin. extracting info from payload Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":514,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5193 Kbps","isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus play Feb 20 19:07:37 rivo volumio[3113]: info: Received an update from plugin. extracting info from payload Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":679,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5270 Kbps","isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus play Feb 20 19:07:37 rivo volumio[3113]: info: Received an update from plugin. extracting info from payload Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 217ms Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 419ms Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 417ms Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 410ms Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 353ms Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 348ms Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 346ms Feb 20 19:07:37 rivo volumio[3113]: info: camilladsp spawned new process with pid 6159, instance 1, run: true Feb 20 19:07:37 rivo volumio[3113]: info: sendMpdCommand playlistinfo took 340 milliseconds Feb 20 19:07:37 rivo volumio[3113]: verbose: ControllerMpd::parseTrackInfo Feb 20 19:07:37 rivo volumio[3113]: info: ControllerMpd::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::servicePushState Feb 20 19:07:37 rivo volumio[3113]: info: CorePlayQueue::getTrack 4 Feb 20 19:07:37 rivo volumio[3113]: verbose: STATE SERVICE {"status":"play","position":0,"seek":679,"duration":249,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5270 Kbps","isStreaming":false,"title":"32087911","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/32087911","trackType":"qobuz"} Feb 20 19:07:37 rivo volumio[3113]: verbose: CURRENT POSITION 4 Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState stateService play Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::syncState currentStatus play Feb 20 19:07:37 rivo volumio[3113]: info: Received an update from plugin. extracting info from payload Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreStateMachine::pushState Feb 20 19:07:37 rivo volumio[3113]: info: CoreCommandRouter::volumioPushState Feb 20 19:07:37 rivo volumio[3113]: info: ------------------------------ 435ms Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: Signalling Playback active due to playback status change Feb 20 19:07:37 rivo volumio[3113]: info: MCU Signalled Playback Active Feb 20 19:07:55 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 19:07:55 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 19:07:55 rivo volumio[3113]: info: Discovery: Getting this device information Feb 20 19:07:55 rivo volumio[3113]: info: CoreCommandRouter::volumioGetState Feb 20 19:07:55 rivo volumio[3113]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 19:08:06 rivo volumio[3113]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 19:08:06 rivo volumio[3113]: Error: connect ETIMEDOUT 151.101.74.79:443 Feb 20 19:08:06 rivo volumio[3113]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Feb 20 19:08:06 rivo volumio[3113]: errno: -110, Feb 20 19:08:06 rivo volumio[3113]: code: 'ETIMEDOUT', Feb 20 19:08:06 rivo volumio[3113]: syscall: 'connect', Feb 20 19:08:06 rivo volumio[3113]: address: '151.101.74.79', Feb 20 19:08:06 rivo volumio[3113]: port: 443 Feb 20 19:08:06 rivo volumio[3113]: } Feb 20 19:08:06 rivo volumio[3113]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 19:08:07 rivo sudo[6340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-20 19:07 Feb 20 19:08:07 rivo sudo[6340]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"