-- Logs begin at Thu 2019-02-14 13:11:58 MSK, end at Mon 2025-09-01 17:57:50 MSK. -- Sep 01 17:56:10 volumio ntpd[1122]: receive: Unexpected origin timestamp 0xec60328a.ac725bf5 does not match aorg 0000000000.00000000 from server@92.255.126.3 xmt 0xec60328a.ad873d90 Sep 01 17:56:21 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Sep 01 17:56:23 volumio volumio[1084]: info: handleBrowseUri took 1751 milliseconds Sep 01 17:56:23 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209389 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209390 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209391 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209392 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209393 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209394 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209395 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209396 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209397 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209398 Sep 01 17:56:23 volumio volumio[1084]: info: Preloading song: qobuz://song/352209399 Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209389 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209390 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209391 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209392 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209393 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209394 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209395 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Executing endpoint getSimilarAlbums Sep 01 17:56:23 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209396 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Executing endpoint metavolumio Sep 01 17:56:23 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 17:56:23 volumio volumio[1084]: info: Executing endpoint metavolumio Sep 01 17:56:23 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209397 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209398 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: Exploding uri qobuz://song/352209399 in service qobuz Sep 01 17:56:23 volumio volumio[1084]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 01 17:56:23 volumio volumio[1084]: info: explodeUri took 576 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 555 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 537 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 562 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 612 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 578 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 565 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 907 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 595 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 755 milliseconds Sep 01 17:56:24 volumio volumio[1084]: info: explodeUri took 701 milliseconds Sep 01 17:56:26 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:26 volumio volumio[1084]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::ClearQueue Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::stop Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::clearPlayQueue Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:26 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::addQueueItems Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::addQueueItems Sep 01 17:56:26 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209389 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209389 Sep 01 17:56:26 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::updateTrackBlock Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::getTrackBlock Sep 01 17:56:26 volumio volumio[1084]: info: CoreCommandRouter::volumioPlay Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::play index 0 Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::addQueueItems Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::addQueueItems Sep 01 17:56:26 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209390 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209390 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209391 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209391 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209392 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209392 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209393 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209393 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209394 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209394 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209395 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209395 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209396 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209396 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209397 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209397 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209398 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209398 Sep 01 17:56:26 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209399 Sep 01 17:56:26 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209399 Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::stop Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:26 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::play index undefined Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::updateTrackBlock Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::getTrackBlock Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:26 volumio volumio[1084]: info: CoreStateMachine::startPlaybackTimer Sep 01 17:56:26 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:26 volumio volumio[1084]: info: [1756738586907] ControllerQobuz::clearAddPlayTrack Sep 01 17:56:26 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand stop Sep 01 17:56:26 volumio volumio[1084]: info: sendMpdCommand stop took 4 milliseconds Sep 01 17:56:26 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand clear Sep 01 17:56:26 volumio volumio[1084]: info: Sep 01 17:56:26 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:26 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:26 volumio volumio[1084]: info: sendMpdCommand clear took 2 milliseconds Sep 01 17:56:26 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:26 volumio volumio[1084]: STREAMING PROXY: Handling url /?data=qobuz://song/352209389 Sep 01 17:56:26 volumio volumio[1084]: info: Sep 01 17:56:26 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:26 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:26 volumio volumio[1084]: error: updateQueue error: null Sep 01 17:56:26 volumio volumio[1084]: info: ------------------------------ 6ms Sep 01 17:56:26 volumio volumio[1084]: info: Executing endpoint getStreamUrlqobuz Sep 01 17:56:26 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Sep 01 17:56:27 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 17:56:27 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 17:56:27 volumio volumio[1084]: info: Discovery: Getting this device information Sep 01 17:56:27 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:27 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:27 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 17:56:28 volumio volumio[1084]: info: getStreamUrl took 1522 milliseconds Sep 01 17:56:28 volumio volumio[1084]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=6550863&eid=352209389&fmt=7&profile=raw&app_id=539451548&cid=2989300&etsp=1756742188&hmac=Z-XsZlcAeNKFGuoCtDzDokjqqdM Sep 01 17:56:30 volumio volumio[1084]: info: CoreCommandRouter::volumioPlay Sep 01 17:56:30 volumio volumio[1084]: info: CoreStateMachine::play index undefined Sep 01 17:56:30 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:30 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:30 volumio volumio[1084]: info: CoreStateMachine::startPlaybackTimer Sep 01 17:56:30 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:30 volumio volumio[1084]: info: [1756738590076] ControllerQobuz::clearAddPlayTrack Sep 01 17:56:30 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand stop Sep 01 17:56:30 volumio volumio[1084]: STREAMING PROXY: Response: 200, length: 66924521 Sep 01 17:56:30 volumio volumio[1084]: STREAMING PROXY: Client dropped request, destroying Sep 01 17:56:30 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:30 volumio volumio[1084]: error: updateQueue error: null Sep 01 17:56:30 volumio volumio[1084]: info: Sep 01 17:56:30 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:30 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:30 volumio volumio[1084]: info: ------------------------------ 3388ms Sep 01 17:56:30 volumio volumio[1084]: info: sendMpdCommand stop took 230 milliseconds Sep 01 17:56:30 volumio volumio[1084]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" took 2 milliseconds Sep 01 17:56:30 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand clear Sep 01 17:56:30 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 01 17:56:30 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand play Sep 01 17:56:30 volumio volumio[1084]: info: Sep 01 17:56:30 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:30 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:30 volumio volumio[1084]: info: Sep 01 17:56:30 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:30 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:30 volumio volumio[1084]: info: ------------------------------ 4ms Sep 01 17:56:30 volumio volumio[1084]: info: sendMpdCommand clear took 3 milliseconds Sep 01 17:56:30 volumio volumio[1084]: info: sendMpdCommand play took 2 milliseconds Sep 01 17:56:30 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:30 volumio volumio[1084]: error: updateQueue error: null Sep 01 17:56:30 volumio volumio[1084]: info: ------------------------------ 3ms Sep 01 17:56:30 volumio volumio[1084]: info: Sep 01 17:56:30 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:30 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:30 volumio volumio[1084]: STREAMING PROXY: Handling url /?data=qobuz://song/352209389 Sep 01 17:56:30 volumio volumio[1084]: info: Executing endpoint getStreamUrlqobuz Sep 01 17:56:30 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Sep 01 17:56:31 volumio volumio[1084]: info: getStreamUrl took 1449 milliseconds Sep 01 17:56:31 volumio volumio[1084]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=6550863&eid=352209389&fmt=7&profile=raw&app_id=539451548&cid=2989300&etsp=1756742191&hmac=eqwed7ed6f41E9AA--TXU3dHM_8 Sep 01 17:56:31 volumio volumio[1084]: STREAMING PROXY: Response: 200, length: 66924521 Sep 01 17:56:31 volumio volumio[1084]: STREAMING PROXY: Client dropped request, destroying Sep 01 17:56:31 volumio volumio[1084]: error: updateQueue error: null Sep 01 17:56:31 volumio volumio[1084]: info: ------------------------------ 1614ms Sep 01 17:56:31 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:31 volumio volumio[1084]: error: updateQueue error: null Sep 01 17:56:31 volumio volumio[1084]: info: Sep 01 17:56:31 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:31 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:31 volumio volumio[1084]: info: ------------------------------ 1615ms Sep 01 17:56:31 volumio volumio[1084]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" took 2 milliseconds Sep 01 17:56:31 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 01 17:56:31 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand play Sep 01 17:56:31 volumio volumio[1084]: info: Sep 01 17:56:31 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:31 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:31 volumio volumio[1084]: info: ------------------------------ 4ms Sep 01 17:56:31 volumio volumio[1084]: info: sendMpdCommand play took 3 milliseconds Sep 01 17:56:31 volumio volumio[1084]: STREAMING PROXY: Handling url /?data=qobuz://song/352209389 Sep 01 17:56:31 volumio volumio[1084]: info: ------------------------------ 2ms Sep 01 17:56:31 volumio volumio[1084]: info: Executing endpoint getStreamUrlqobuz Sep 01 17:56:31 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Sep 01 17:56:32 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::ClearQueue Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::stop Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::clearPlayQueue Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::addQueueItems Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::addQueueItems Sep 01 17:56:32 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209389 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209389 Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::updateTrackBlock Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::getTrackBlock Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioPlay Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::play index 0 Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::addQueueItems Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::addQueueItems Sep 01 17:56:32 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209390 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209390 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209391 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209391 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209392 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209392 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209393 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209393 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209394 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209394 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209395 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209395 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209396 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209396 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209397 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209397 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209398 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209398 Sep 01 17:56:32 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209399 Sep 01 17:56:32 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209399 Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::stop Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::play index undefined Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::updateTrackBlock Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::getTrackBlock Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::startPlaybackTimer Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:32 volumio volumio[1084]: info: [1756738592172] ControllerQobuz::clearAddPlayTrack Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand stop Sep 01 17:56:32 volumio volumio[1084]: info: Sep 01 17:56:32 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:32 volumio volumio[1084]: info: sendMpdCommand stop took 4 milliseconds Sep 01 17:56:32 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand clear Sep 01 17:56:32 volumio volumio[1084]: info: Sep 01 17:56:32 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:32 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:32 volumio volumio[1084]: info: sendMpdCommand status took 2 milliseconds Sep 01 17:56:32 volumio volumio[1084]: info: sendMpdCommand clear took 2 milliseconds Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:32 volumio volumio[1084]: info: Sep 01 17:56:32 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:32 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:32 volumio volumio[1084]: error: updateQueue error: null Sep 01 17:56:32 volumio volumio[1084]: STREAMING PROXY: Handling url /?data=qobuz://song/352209389 Sep 01 17:56:32 volumio volumio[1084]: info: ------------------------------ 4ms Sep 01 17:56:32 volumio volumio[1084]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::parseTrackInfo Sep 01 17:56:32 volumio volumio[1084]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 01 17:56:32 volumio volumio[1084]: info: ------------------------------ 8ms Sep 01 17:56:32 volumio volumio[1084]: info: Executing endpoint getStreamUrlqobuz Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Sep 01 17:56:32 volumio volumio[1084]: info: getStreamUrl took 469 milliseconds Sep 01 17:56:32 volumio volumio[1084]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=6550863&eid=352209389&fmt=7&profile=raw&app_id=539451548&cid=2989300&etsp=1756742192&hmac=qcYz8mhPj_KY2KoLGOGN8hA9o3k Sep 01 17:56:32 volumio volumio[1084]: STREAMING PROXY: Response: 200, length: 66924521 Sep 01 17:56:32 volumio volumio[1084]: info: getStreamUrl took 583 milliseconds Sep 01 17:56:32 volumio volumio[1084]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=6550863&eid=352209389&fmt=7&profile=raw&app_id=539451548&cid=2989300&etsp=1756742192&hmac=qcYz8mhPj_KY2KoLGOGN8hA9o3k Sep 01 17:56:32 volumio volumio[1084]: STREAMING PROXY: Response: 200, length: 66924521 Sep 01 17:56:32 volumio volumio[1084]: STREAMING PROXY: Client dropped request, destroying Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:32 volumio volumio[1084]: info: Sep 01 17:56:32 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:32 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:32 volumio volumio[1084]: info: sendMpdCommand status took 742 milliseconds Sep 01 17:56:32 volumio volumio[1084]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" took 1 milliseconds Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 01 17:56:32 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand play Sep 01 17:56:32 volumio volumio[1084]: info: ControllerMpd::pushState Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::servicePushState Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:32 volumio volumio[1084]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 01 17:56:32 volumio volumio[1084]: verbose: CURRENT POSITION 0 Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::syncState stateService stop Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::syncState currentStatus stop Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: No code Sep 01 17:56:32 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:32 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:32 volumio volumio[1084]: STREAMING PROXY: Handling url /?data=qobuz://song/352209389 Sep 01 17:56:32 volumio volumio[1084]: info: ------------------------------ 779ms Sep 01 17:56:32 volumio volumio[1084]: info: Sep 01 17:56:32 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:32 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:32 volumio volumio[1084]: info: ------------------------------ 42ms Sep 01 17:56:32 volumio volumio[1084]: info: sendMpdCommand play took 38 milliseconds Sep 01 17:56:32 volumio volumio[1084]: info: ------------------------------ 2ms Sep 01 17:56:32 volumio volumio[1084]: info: Sep 01 17:56:32 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:32 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:32 volumio volumio[1084]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.X4onpwyKemPwjqTTqkmgR5q3ZYA3.0492201152401c3b68ef86ae22a64abf.state.status' Sep 01 17:56:32 volumio volumio[1084]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.X4onpwyKemPwjqTTqkmgR5q3ZYA3.0492201152401c3b68ef86ae22a64abf.state.status' Sep 01 17:56:33 volumio volumio[1084]: info: ------------------------------ 39ms Sep 01 17:56:33 volumio volumio[1084]: info: Executing endpoint getStreamUrlqobuz Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Sep 01 17:56:33 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::ClearQueue Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::stop Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::clearPlayQueue Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::addQueueItems Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::addQueueItems Sep 01 17:56:33 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209389 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209389 Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::updateTrackBlock Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::getTrackBlock Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioPlay Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::play index 0 Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::addQueueItems Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::addQueueItems Sep 01 17:56:33 volumio volumio[1084]: info: Preload queue cleared Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209390 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209390 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209391 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209391 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209392 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209392 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209393 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209393 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209394 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209394 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209395 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209395 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209396 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209396 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209397 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209397 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209398 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209398 Sep 01 17:56:33 volumio volumio[1084]: info: Adding Item to queue: qobuz://song/352209399 Sep 01 17:56:33 volumio volumio[1084]: info: Using cached record of: qobuz://song/352209399 Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::stop Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioPushQueue Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::saveQueue Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::play index undefined Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::updateTrackBlock Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::getTrackBlock Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::startPlaybackTimer Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:33 volumio volumio[1084]: info: [1756738593111] ControllerQobuz::clearAddPlayTrack Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand stop Sep 01 17:56:33 volumio volumio[1084]: info: Sep 01 17:56:33 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:33 volumio volumio[1084]: info: sendMpdCommand stop took 5 milliseconds Sep 01 17:56:33 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand clear Sep 01 17:56:33 volumio volumio[1084]: info: Sep 01 17:56:33 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:33 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:33 volumio volumio[1084]: info: sendMpdCommand status took 2 milliseconds Sep 01 17:56:33 volumio volumio[1084]: info: sendMpdCommand clear took 1 milliseconds Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:33 volumio volumio[1084]: info: Sep 01 17:56:33 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:33 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:33 volumio volumio[1084]: error: updateQueue error: null Sep 01 17:56:33 volumio volumio[1084]: STREAMING PROXY: Handling url /?data=qobuz://song/352209389 Sep 01 17:56:33 volumio volumio[1084]: info: ------------------------------ 4ms Sep 01 17:56:33 volumio volumio[1084]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::parseTrackInfo Sep 01 17:56:33 volumio volumio[1084]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 01 17:56:33 volumio volumio[1084]: info: ------------------------------ 7ms Sep 01 17:56:33 volumio volumio[1084]: info: Executing endpoint getStreamUrlqobuz Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Sep 01 17:56:33 volumio volumio[1084]: info: getStreamUrl took 479 milliseconds Sep 01 17:56:33 volumio volumio[1084]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=6550863&eid=352209389&fmt=7&profile=raw&app_id=539451548&cid=2989300&etsp=1756742193&hmac=TXzsrKU82fr7IyWNNJopg4u3FxA Sep 01 17:56:33 volumio volumio[1084]: STREAMING PROXY: Response: 200, length: 66924521 Sep 01 17:56:33 volumio volumio[1084]: info: getStreamUrl took 468 milliseconds Sep 01 17:56:33 volumio volumio[1084]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=6550863&eid=352209389&fmt=7&profile=raw&app_id=539451548&cid=2989300&etsp=1756742193&hmac=TXzsrKU82fr7IyWNNJopg4u3FxA Sep 01 17:56:33 volumio volumio[1084]: STREAMING PROXY: Response: 200, length: 66924521 Sep 01 17:56:33 volumio volumio[1084]: STREAMING PROXY: Client dropped request, destroying Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" Sep 01 17:56:33 volumio volumio[1084]: info: Sep 01 17:56:33 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:33 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:33 volumio volumio[1084]: info: sendMpdCommand status took 602 milliseconds Sep 01 17:56:33 volumio volumio[1084]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/352209389" took 4 milliseconds Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 01 17:56:33 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand play Sep 01 17:56:33 volumio volumio[1084]: info: ControllerMpd::pushState Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::servicePushState Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:33 volumio volumio[1084]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 01 17:56:33 volumio volumio[1084]: verbose: CURRENT POSITION 0 Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::syncState stateService stop Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::syncState currentStatus stop Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: No code Sep 01 17:56:33 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:33 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:33 volumio volumio[1084]: STREAMING PROXY: Handling url /?data=qobuz://song/352209389 Sep 01 17:56:33 volumio volumio[1084]: info: ------------------------------ 637ms Sep 01 17:56:33 volumio volumio[1084]: info: Sep 01 17:56:33 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:33 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:33 volumio volumio[1084]: info: ------------------------------ 41ms Sep 01 17:56:33 volumio volumio[1084]: info: sendMpdCommand play took 40 milliseconds Sep 01 17:56:33 volumio volumio[1084]: info: ------------------------------ 5ms Sep 01 17:56:33 volumio volumio[1084]: info: Sep 01 17:56:33 volumio volumio[1084]: ---------------------------- MPD announces system playlist update Sep 01 17:56:33 volumio volumio[1084]: info: Ignoring MPD Status Update Sep 01 17:56:33 volumio volumio[1084]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.X4onpwyKemPwjqTTqkmgR5q3ZYA3.0492201152401c3b68ef86ae22a64abf.state.status' Sep 01 17:56:33 volumio volumio[1084]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.X4onpwyKemPwjqTTqkmgR5q3ZYA3.0492201152401c3b68ef86ae22a64abf.state.status' Sep 01 17:56:33 volumio volumio[1084]: info: ------------------------------ 13ms Sep 01 17:56:33 volumio volumio[1084]: info: Executing endpoint getStreamUrlqobuz Sep 01 17:56:33 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Sep 01 17:56:34 volumio volumio[1084]: info: getStreamUrl took 545 milliseconds Sep 01 17:56:34 volumio volumio[1084]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=6550863&eid=352209389&fmt=7&profile=raw&app_id=539451548&cid=2989300&etsp=1756742194&hmac=aBK4n_x_f5wlzsebeRyVSlK-1mU Sep 01 17:56:34 volumio volumio[1084]: STREAMING PROXY: Response: 200, length: 66924521 Sep 01 17:56:34 volumio volumio[1084]: info: Sep 01 17:56:34 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:34 volumio volumio[1084]: info: Sep 01 17:56:34 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand status took 3 milliseconds Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 01 17:56:34 volumio volumio[1084]: info: Sep 01 17:56:34 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand status took 4 milliseconds Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseTrackInfo Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::servicePushState Sep 01 17:56:34 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:34 volumio volumio[1084]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":290,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"352209389","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/352209389","trackType":"qobuz"} Sep 01 17:56:34 volumio volumio[1084]: verbose: CURRENT POSITION 0 Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState stateService play Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState currentStatus stop Sep 01 17:56:34 volumio volumio[1084]: info: ------------------------------ 11ms Sep 01 17:56:34 volumio volumio[1084]: info: Sep 01 17:56:34 volumio volumio[1084]: ---------------------------- MPD announces state update: player Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::getState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand status Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand status took 7 milliseconds Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseTrackInfo Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::servicePushState Sep 01 17:56:34 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:34 volumio volumio[1084]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":290,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"352209389","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/352209389","trackType":"qobuz"} Sep 01 17:56:34 volumio volumio[1084]: verbose: CURRENT POSITION 0 Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState stateService play Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState currentStatus play Sep 01 17:56:34 volumio volumio[1084]: info: Received an update from plugin. extracting info from payload Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: ------------------------------ 42ms Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand status took 32 milliseconds Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand playlistinfo took 31 milliseconds Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseState Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseTrackInfo Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::servicePushState Sep 01 17:56:34 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:34 volumio volumio[1084]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":290,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"352209389","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/352209389","trackType":"qobuz"} Sep 01 17:56:34 volumio volumio[1084]: verbose: CURRENT POSITION 0 Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState stateService play Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState currentStatus play Sep 01 17:56:34 volumio volumio[1084]: info: Received an update from plugin. extracting info from payload Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: ------------------------------ 89ms Sep 01 17:56:34 volumio volumio[1084]: info: sendMpdCommand playlistinfo took 111 milliseconds Sep 01 17:56:34 volumio volumio[1084]: verbose: ControllerMpd::parseTrackInfo Sep 01 17:56:34 volumio volumio[1084]: info: ControllerMpd::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::servicePushState Sep 01 17:56:34 volumio volumio[1084]: info: CorePlayQueue::getTrack 0 Sep 01 17:56:34 volumio volumio[1084]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":290,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"352209389","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/352209389","trackType":"qobuz"} Sep 01 17:56:34 volumio volumio[1084]: verbose: CURRENT POSITION 0 Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState stateService play Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::syncState currentStatus play Sep 01 17:56:34 volumio volumio[1084]: info: Received an update from plugin. extracting info from payload Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreStateMachine::pushState Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioPushState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output update for this device Sep 01 17:56:34 volumio volumio[1084]: info: MRS: Pushing multiroomSync output Sep 01 17:56:34 volumio volumio[1084]: info: ------------------------------ 173ms Sep 01 17:56:36 volumio volumio[1084]: info: Executing endpoint metavolumio Sep 01 17:56:36 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 17:56:36 volumio volumio[1084]: info: Executing endpoint metavolumio Sep 01 17:56:36 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 17:56:36 volumio volumio[1084]: info: Executing endpoint metavolumio Sep 01 17:56:36 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:56:42 volumio volumio[1084]: info: Retrieving Cloud Streaming UI Sep 01 17:56:42 volumio volumio[1084]: info: Getting Tidal Cloud Configuration Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:56:42 volumio volumio[1084]: info: Getting Qobuz Cloud Configuration Sep 01 17:56:42 volumio volumio[1084]: info: Asking plugin for UI Config Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:56:42 volumio volumio[1084]: info: Getting Spotify Cloud Configuration Sep 01 17:56:42 volumio volumio[1084]: info: Asking plugin for UI Config Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:56:42 volumio volumio[1084]: info: Saving Spotify Acccount Sep 01 17:56:42 volumio volumio[1084]: info: Got it Sep 01 17:56:42 volumio volumio[1084]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 17:56:42 volumio volumio[1084]: info: Got Tidal Cloud Configuration Sep 01 17:56:42 volumio volumio[1084]: info: Got it Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 17:56:42 volumio volumio[1084]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 17:56:43 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:56:43 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Sep 01 17:56:46 volumio volumio[1084]: info: Disabling MyMusic plugin bluetooth Sep 01 17:56:46 volumio volumio[1084]: info: [MyVolumio PluginManager] Disabling and stopping plugin audio_interface bluetooth Sep 01 17:56:46 volumio sudo[15534]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumiobt.service Sep 01 17:56:46 volumio sudo[15534]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 17:56:46 volumio systemd[1]: Stopping Volumio Bluetooth Module... Sep 01 17:56:46 volumio volumiobt[15540]: Killing pulse Sep 01 17:56:46 volumio volumio[1084]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 01 17:56:46 volumio bluetoothd[593]: Endpoint unregistered: sender=:1.46 path=/MediaEndpoint/A2DPSource Sep 01 17:56:46 volumio bluetoothd[593]: Endpoint unregistered: sender=:1.46 path=/MediaEndpoint/A2DPSink Sep 01 17:56:46 volumio volumiobt[15540]: Killing BT Pair agent Sep 01 17:56:46 volumio volumiobt[2188]: Terminated Sep 01 17:56:46 volumio systemd[1]: volumiobt.service: Main process exited, code=killed, status=15/TERM Sep 01 17:56:46 volumio systemd[1]: volumiobt.service: Succeeded. Sep 01 17:56:46 volumio systemd[1]: Stopped Volumio Bluetooth Module. Sep 01 17:56:46 volumio sudo[15534]: pam_unix(sudo:session): session closed for user root Sep 01 17:56:46 volumio volumio[1084]: info: Volumio BT Module successfully stopped Sep 01 17:56:46 volumio volumio[1084]: info: Disabling plugin bluetooth Sep 01 17:56:47 volumio volumio[1084]: info: Enabling MyMusic plugin bluetooth Sep 01 17:56:47 volumio volumio[1084]: info: [MyVolumio PluginManager] Enabling and starting plugin audio_interface bluetooth Sep 01 17:56:47 volumio volumio[1084]: info: Enabling plugin bluetooth Sep 01 17:56:47 volumio volumio[1084]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Sep 01 17:56:47 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 17:56:47 volumio volumio[1084]: info: Done. Sep 01 17:56:47 volumio sudo[15549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Sep 01 17:56:47 volumio sudo[15549]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 17:56:47 volumio sudo[15549]: pam_unix(sudo:session): session closed for user root Sep 01 17:56:47 volumio volumio[1084]: info: Bluetooth name changed to Volumio Sep 01 17:56:47 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:56:50 volumio sudo[15559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Sep 01 17:56:50 volumio sudo[15559]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 17:56:50 volumio systemd[1]: Started Volumio Bluetooth Module. Sep 01 17:56:50 volumio sudo[15559]: pam_unix(sudo:session): session closed for user root Sep 01 17:56:50 volumio sudo[15566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Sep 01 17:56:50 volumio volumio[1084]: info: Volumio BT Module successfully started Sep 01 17:56:50 volumio sudo[15566]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 17:56:50 volumio volumiobt[15565]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Sep 01 17:56:50 volumio sudo[15566]: pam_unix(sudo:session): session closed for user root Sep 01 17:56:51 volumio sudo[15594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Sep 01 17:56:51 volumio sudo[15594]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 17:56:51 volumio volumiobt[15565]: pulseaudio: no process found Sep 01 17:56:51 volumio sudo[15594]: pam_unix(sudo:session): session closed for user root Sep 01 17:56:51 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:56:51 volumio pulseaudio[15605]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Sep 01 17:56:51 volumio pulseaudio[15605]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Sep 01 17:56:51 volumio volumiobt[15565]: Applying permissions Sep 01 17:56:51 volumio volumiobt[15565]: Setting BT discoverable and pairable Sep 01 17:56:51 volumio bluetoothd[593]: Endpoint registered: sender=:1.82 path=/MediaEndpoint/A2DPSource Sep 01 17:56:51 volumio bluetoothd[593]: Endpoint registered: sender=:1.82 path=/MediaEndpoint/A2DPSink Sep 01 17:56:51 volumio pulseaudio[15605]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Sep 01 17:56:51 volumio volumiobt[15565]: Agent registered Sep 01 17:56:51 volumio volumiobt[15565]: [bluetooth]# -e power on Sep 01 17:56:51 volumio volumiobt[15565]: Invalid command in menu main: -e Sep 01 17:56:51 volumio volumiobt[15565]: Sep 01 17:56:51 volumio volumiobt[15565]: Use "help" for a list of available commands in a menu. Sep 01 17:56:51 volumio volumiobt[15565]: Use "menu " if you want to enter any submenu. Sep 01 17:56:51 volumio volumiobt[15565]: Use "back" if you want to return to menu main. Sep 01 17:56:51 volumio volumiobt[15565]: [bluetooth]# agent on Sep 01 17:56:51 volumio volumiobt[15565]: Agent is already registered Sep 01 17:56:51 volumio volumiobt[15565]: [bluetooth]# discoverable on Sep 01 17:56:51 volumio volumiobt[15565]: [bluetooth]# pairable on Sep 01 17:56:51 volumio volumiobt[15565]: [bluetooth]# agent NoInputNoOutput Sep 01 17:56:51 volumio volumiobt[15565]: Agent is already registered Sep 01 17:56:51 volumio volumiobt[15565]: [bluetooth]# default-agent Sep 01 17:56:51 volumio volumiobt[15565]: [bluetooth]# quit Sep 01 17:56:51 volumio volumiobt[15565]: [59B blob data] Sep 01 17:56:55 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:56:57 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 17:56:57 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 17:56:57 volumio volumio[1084]: info: Discovery: Getting this device information Sep 01 17:56:57 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:56:57 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 17:56:59 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:57:03 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:57:03 volumio volumio[1084]: STREAMING PROXY: Client dropped request, destroying Sep 01 17:57:04 volumio volumio[1084]: info: Disabling MyMusic plugin smart_inputs Sep 01 17:57:04 volumio volumio[1084]: info: [MyVolumio PluginManager] Disabling and stopping plugin music_service smart_inputs Sep 01 17:57:04 volumio volumio[1084]: info: Removeing all smart Inputs Sep 01 17:57:04 volumio volumio[1084]: info: Disabling plugin smart_inputs Sep 01 17:57:07 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:57:07 volumio volumio[1084]: info: Enabling MyMusic plugin smart_inputs Sep 01 17:57:07 volumio volumio[1084]: info: [MyVolumio PluginManager] Enabling and starting plugin music_service smart_inputs Sep 01 17:57:07 volumio volumio[1084]: info: Enabling plugin smart_inputs Sep 01 17:57:07 volumio volumio[1084]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Sep 01 17:57:07 volumio volumio[1084]: info: Adding inputs REST Endpoints Sep 01 17:57:07 volumio volumio[1084]: info: Updating scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Sep 01 17:57:07 volumio volumio[1084]: info: Scanning Audio Inputs Sep 01 17:57:07 volumio volumio[1084]: No protocol specified Sep 01 17:57:07 volumio volumio[1084]: xcb_connection_has_error() returned true Sep 01 17:57:07 volumio volumio[1084]: info: Checking against Known Cards name Sep 01 17:57:07 volumio volumio[1084]: info: Checking against Known Cards name Sep 01 17:57:07 volumio volumio[1084]: info: Checking against Known Cards name Sep 01 17:57:07 volumio volumio[1084]: info: Adding Server instance for streaming Sep 01 17:57:07 volumio volumio[1084]: info: Done. Sep 01 17:57:11 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:57:22 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:57:22 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 17:57:22 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 17:57:22 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 17:57:22 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Sep 01 17:57:23 volumio volumio[1084]: info: Received Get System Version Sep 01 17:57:23 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 17:57:27 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 17:57:27 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 17:57:27 volumio volumio[1084]: info: Discovery: Getting this device information Sep 01 17:57:27 volumio volumio[1084]: info: CoreCommandRouter::volumioGetState Sep 01 17:57:27 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:57:41 volumio volumio[1084]: info: Retrieving Cloud Streaming UI Sep 01 17:57:41 volumio volumio[1084]: info: Getting Tidal Cloud Configuration Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:57:41 volumio volumio[1084]: info: Getting Qobuz Cloud Configuration Sep 01 17:57:41 volumio volumio[1084]: info: Asking plugin for UI Config Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:57:41 volumio volumio[1084]: info: Getting Spotify Cloud Configuration Sep 01 17:57:41 volumio volumio[1084]: info: Asking plugin for UI Config Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:57:41 volumio volumio[1084]: info: Saving Spotify Acccount Sep 01 17:57:41 volumio volumio[1084]: info: Got it Sep 01 17:57:41 volumio volumio[1084]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 01 17:57:41 volumio volumio[1084]: info: Got Tidal Cloud Configuration Sep 01 17:57:41 volumio volumio[1084]: info: Got it Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 17:57:41 volumio volumio[1084]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 17:57:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:57:42 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Sep 01 17:57:46 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 01 17:57:48 volumio volumio[1084]: info: Disabling MyMusic plugin upnp Sep 01 17:57:48 volumio sudo[15749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Sep 01 17:57:48 volumio sudo[15749]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 17:57:48 volumio volumio[1084]: error: Upnp client error: Error: This socket has been ended by the other party Sep 01 17:57:48 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Sep 01 17:57:48 volumio volumio[1084]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 01 17:57:48 volumio volumio[1084]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 01 17:57:50 volumio volumio[1084]: info: Enabling MyMusic plugin upnp Sep 01 17:57:50 volumio volumio[1084]: info: Enabling plugin upnp Sep 01 17:57:50 volumio volumio[1084]: info: Loading plugin "upnp"... Sep 01 17:57:50 volumio volumio[1084]: info: [1756738670346] Starting Upmpd Daemon Sep 01 17:57:50 volumio volumio[1084]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 17:57:50 volumio volumio[1084]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 17:57:50 volumio volumio[1084]: Error: listen EADDRINUSE: address already in use :::6599 Sep 01 17:57:50 volumio volumio[1084]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Sep 01 17:57:50 volumio volumio[1084]: at listenInCluster (net.js:1379:12) Sep 01 17:57:50 volumio volumio[1084]: at Server.listen (net.js:1465:7) Sep 01 17:57:50 volumio volumio[1084]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Sep 01 17:57:50 volumio volumio[1084]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Sep 01 17:57:50 volumio volumio[1084]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Sep 01 17:57:50 volumio volumio[1084]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Sep 01 17:57:50 volumio volumio[1084]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Sep 01 17:57:50 volumio volumio[1084]: code: 'EADDRINUSE', Sep 01 17:57:50 volumio volumio[1084]: errno: -98, Sep 01 17:57:50 volumio volumio[1084]: syscall: 'listen', Sep 01 17:57:50 volumio volumio[1084]: address: '::', Sep 01 17:57:50 volumio volumio[1084]: port: 6599 Sep 01 17:57:50 volumio volumio[1084]: } Sep 01 17:57:50 volumio volumio[1084]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 17:57:50 volumio sudo[15764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-01 17:56 Sep 01 17:57:50 volumio sudo[15764]: 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="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:55:15 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="2f3686ade78abf3b92c180a0c5b20c6b"