-- Logs begin at Thu 2026-03-12 12:13:14 +11, end at Fri 2026-03-27 20:26:23 +11. --
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Preload queue cleared
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioReplaceandPlayItems
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::ClearQueue
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::stop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::stPlaybackTimer
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::updateTrackBlock
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrackBlock
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 2
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 2
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::serviceStop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 2
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::serviceStop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: [1774603521240] ControllerQobuz::stop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::stop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand stop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::clearPlayQueue
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::saveQueue
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushQueue
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::addQueueItems
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::addQueueItems
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Preload queue cleared
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148702
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148702 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/24103643
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/24103643 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148692
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148692 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148690
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148690 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148689
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148689 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148693
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148693 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/24103654
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/24103654 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148694
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148694 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/52576874
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/52576874 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148691
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148691 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148697
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148697 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/132314788
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/132314788 in service qobuz
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.257+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_STOPPED positionMs=0 volume=100
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.258+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/4713592 title="Why Don't We Just Sleep On It Tonight"
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces state update: player
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand stop took 58 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::getState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand status
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand status took 14 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseTrackInfo
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::pushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::servicePushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 2
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4713592","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/4713592","trackType":"qobuz"}
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: verbose: CURRENT POSITION 2
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState stateService stop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState currentStatus stop
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: No code
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.362+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=0 volume=100
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.363+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/48902008 title="Sleep on It"
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.365+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=0 volume=100
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.365+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/48902008 title="Sleep on It"
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.367+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=0 volume=100
Mar 27 20:25:21 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:21.367+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/48902008 title="Sleep on It"
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 99ms
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 588 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 597 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 623 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 626 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 629 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 664 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 666 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 678 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 703 milliseconds
Mar 27 20:25:21 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 705 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 817 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 814 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushQueue
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::saveQueue
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::updateTrackBlock
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrackBlock
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPlay
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::play index 11
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::addQueueItems
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::addQueueItems
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Preload queue cleared
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148696
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148696 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148695
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148695 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148698
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148698 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148700
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148700 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/24103641
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/24103641 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/24103642
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/24103642 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/24103646
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/24103646 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/2148699
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/2148699 in service qobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::stop
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::play index undefined
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::startPlaybackTimer
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetVisibleSources
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: [1774603522086] ControllerQobuz::clearAddPlayTrack
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand stop
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand stop took 21 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand clear
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces system playlist update
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Ignoring MPD Status Update
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand clear took 2 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/132314788"
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: error: updateQueue error: null
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Handling url /?data=qobuz://song/132314788
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 3ms
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint getStreamUrlqobuz
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 496 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 500 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 498 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 507 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 535 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 532 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: getStreamUrl took 498 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3188743&eid=132314788&fmt=7&profile=raw&app_id=539451548&cid=2368744&etsp=1774607122&hmac=S4sew-IHy7ucT_txmz5xh-ooVio
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Requesting upstream with range: none
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 540 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 591 milliseconds
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushQueue
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::saveQueue
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::updateTrackBlock
Mar 27 20:25:22 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrackBlock
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream status code: 200
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Client closed connection
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream closed. Received 15644 bytes
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Incomplete transfer. Expected 44039336, got 15644
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Retrying with range: bytes=15644- (attempt 1)
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/132314788"
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces system playlist update
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: Ignoring MPD Status Update
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/132314788" took 1 milliseconds
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand play
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 2ms
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand play took 1 milliseconds
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Handling url /?data=qobuz://song/132314788
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint getStreamUrlqobuz
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: getStreamUrl took 430 milliseconds
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3188743&eid=132314788&fmt=7&profile=raw&app_id=539451548&cid=2368744&etsp=1774607124&hmac=l9lafIvZ4M7nFqn_AR1nIDYlwLk
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Requesting upstream with range: none
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream status code: 200
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces state update: player
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::getState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand status
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces state update: player
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand status took 1 milliseconds
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::getState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand status
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand status took 1 milliseconds
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseTrackInfo
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::pushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::servicePushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132314788","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/132314788","trackType":"qobuz"}
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: CURRENT POSITION 11
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState stateService play
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState currentStatus stop
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 7ms
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand playlistinfo took 3 milliseconds
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseTrackInfo
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::pushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::servicePushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132314788","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/132314788","trackType":"qobuz"}
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: verbose: CURRENT POSITION 11
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState stateService play
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState currentStatus play
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: Received an update from plugin. extracting info from payload
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:24 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:24.623+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=0 volume=100
Mar 27 20:25:24 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:24.623+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/132314788 title="Angel Dust"
Mar 27 20:25:24 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:24.627+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=0 volume=100
Mar 27 20:25:24 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:24.628+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/132314788 title="Angel Dust"
Mar 27 20:25:24 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 25ms
Mar 27 20:25:25 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resuming with range: bytes=15644-
Mar 27 20:25:25 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resume upstream status code: 206
Mar 27 20:25:31 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream closed. Received 44039336 bytes
Mar 27 20:25:31 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Client closed connection
Mar 27 20:25:32 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resume ended. Received 44023692 bytes
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: Searching all installed plugins
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: , search
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: last_100 , search
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: webradio , search
Mar 27 20:25:49 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: Searching all installed plugins
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: , search
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: last_100 , search
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: webradio , search
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: searchQOBUZUri took 993 milliseconds
Mar 27 20:25:50 du-bon-son-chez-berthet volumio[1043]: info: All search sources collected, pushing search results
Mar 27 20:25:50 du-bon-son-chez-berthet volumiologrotate[629]: ls: cannot access '/var/log/samba/log.wb-DU': No such file or directory
Mar 27 20:25:50 du-bon-son-chez-berthet volumiologrotate[629]: ls: cannot access 'BON': No such file or directory
Mar 27 20:25:50 du-bon-son-chez-berthet volumiologrotate[629]: ls: cannot access 'SON': No such file or directory
Mar 27 20:25:50 du-bon-son-chez-berthet volumiologrotate[629]: ls: cannot access 'CHEZ': No such file or directory
Mar 27 20:25:50 du-bon-son-chez-berthet volumiologrotate[629]: ls: cannot access 'BERTHET': No such file or directory
Mar 27 20:25:51 du-bon-son-chez-berthet volumio[1043]: info: searchQOBUZUri took 933 milliseconds
Mar 27 20:25:51 du-bon-son-chez-berthet volumio[1043]: info: All search sources collected, pushing search results
Mar 27 20:25:51 du-bon-son-chez-berthet ntpd[790]: Soliciting pool server 2404:2a00::31
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: Searching all installed plugins
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: , search
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: last_100 , search
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: webradio , search
Mar 27 20:25:52 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Mar 27 20:25:53 du-bon-son-chez-berthet volumio[1043]: info: searchQOBUZUri took 826 milliseconds
Mar 27 20:25:53 du-bon-son-chez-berthet volumio[1043]: info: All search sources collected, pushing search results
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: Preload queue cleared
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioReplaceandPlayItems
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::ClearQueue
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::stop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::stPlaybackTimer
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::updateTrackBlock
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrackBlock
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::serviceStop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::serviceStop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: [1774603556627] ControllerQobuz::stop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::stop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand stop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::clearPlayQueue
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::saveQueue
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushQueue
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::addQueueItems
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::addQueueItems
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: Preload queue cleared
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: Adding Item to queue: qobuz://song/70054350
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: Exploding uri qobuz://song/70054350 in service qobuz
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.632+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_STOPPED positionMs=0 volume=100
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.633+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/132314788 title="Angel Dust"
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces state update: player
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand stop took 17 milliseconds
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::getState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand status
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand status took 1 milliseconds
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseTrackInfo
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::pushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::servicePushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 11
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132314788","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/132314788","trackType":"qobuz"}
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: verbose: CURRENT POSITION 11
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState stateService stop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState currentStatus stop
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: No code
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.659+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=260 volume=100
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.659+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/132314788 title="Angel Dust"
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.663+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=260 volume=100
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.664+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/132314788 title="Angel Dust"
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.664+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=260 volume=100
Mar 27 20:25:56 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:25:56.665+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/132314788 title="Angel Dust"
Mar 27 20:25:56 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 27ms
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: explodeUri took 488 milliseconds
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushQueue
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::saveQueue
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::updateTrackBlock
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrackBlock
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPlay
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::play index 0
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::stop
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::play index undefined
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 0
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::startPlaybackTimer
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 0
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetVisibleSources
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: [1774603557126] ControllerQobuz::clearAddPlayTrack
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand stop
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand stop took 3 milliseconds
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand clear
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces system playlist update
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: Ignoring MPD Status Update
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand clear took 1 milliseconds
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/70054350"
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: error: updateQueue error: null
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 1ms
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Handling url /?data=qobuz://song/70054350
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint getStreamUrlqobuz
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: info: getStreamUrl took 422 milliseconds
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3188743&eid=70054350&fmt=6&profile=raw&app_id=539451548&cid=2368744&etsp=1774607157&hmac=AMYwvH0H7UMtvO6lkPioZfWFHYI
Mar 27 20:25:57 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Requesting upstream with range: none
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream status code: 200
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/70054350"
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Client closed connection
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream closed. Received 15656 bytes
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Incomplete transfer. Expected 142279349, got 15656
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Retrying with range: bytes=15656- (attempt 1)
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces system playlist update
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: Ignoring MPD Status Update
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/70054350" took 1 milliseconds
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand play
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 2ms
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand play took 1 milliseconds
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Handling url /?data=qobuz://song/70054350
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint getStreamUrlqobuz
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: getStreamUrl took 454 milliseconds
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3188743&eid=70054350&fmt=6&profile=raw&app_id=539451548&cid=2368744&etsp=1774607160&hmac=yo5wLwvcorq8mt5NsaqyJVbAZFk
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Requesting upstream with range: none
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream status code: 200
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces state update: player
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::getState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand status
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces state update: player
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand status took 1 milliseconds
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::getState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand status
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand status took 1 milliseconds
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseTrackInfo
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::pushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::servicePushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 0
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1401,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70054350","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/70054350","trackType":"qobuz"}
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: CURRENT POSITION 0
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState stateService play
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState currentStatus stop
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 6ms
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseTrackInfo
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::pushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::servicePushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 0
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1401,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70054350","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/70054350","trackType":"qobuz"}
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: verbose: CURRENT POSITION 0
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState stateService play
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState currentStatus play
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: Received an update from plugin. extracting info from payload
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:26:00 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:00.570+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=0 volume=100
Mar 27 20:26:00 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:00.572+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/70054350 title="Angel Dust"
Mar 27 20:26:00 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:00.573+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=0 volume=100
Mar 27 20:26:00 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:00.573+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/70054350 title="Angel Dust"
Mar 27 20:26:00 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 21ms
Mar 27 20:26:01 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resuming with range: bytes=15656-
Mar 27 20:26:01 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resume upstream status code: 206
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: Searching all installed plugins
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: , search
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: last_100 , search
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: webradio , search
Mar 27 20:26:11 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Mar 27 20:26:12 du-bon-son-chez-berthet volumio[1043]: info: searchQOBUZUri took 1293 milliseconds
Mar 27 20:26:12 du-bon-son-chez-berthet volumio[1043]: info: All search sources collected, pushing search results
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioSeek
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::seek
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 0
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: TRACKBLOCK {"album":"Ultimate Jazz Collections Gill Scott-Heron, Vol. 16","albumUri":"qobuz://album/ui62iblv6hueb","albumart":"https://static.qobuz.com/images/covers/eb/hu/ui62iblv6hueb_600.jpg","artist":"Gil Scott-Heron","artistUri":"qobuz://artist/148745","audioQuality":"","duration":1400,"explicit":false,"name":"Angel Dust","service":"qobuz","title":"Angel Dust","tracknumber":9,"type":"track","uri":"qobuz://song/70054350","volumeNumber":1,"tagImage":""}
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::startPlaybackTimer
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 0
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetVisibleSources
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: [1774603575164] ControllerQobuz::seek
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::seek
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:26:15 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:15.174+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=170000 volume=100
Mar 27 20:26:15 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:15.175+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/70054350 title="Angel Dust"
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Client closed connection
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Handling url /?data=qobuz://song/70054350
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream closed. Received 71191871 bytes
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Incomplete transfer. Expected 142279349, got 71191871
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Retrying with range: bytes=71191871- (attempt 1)
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint getStreamUrlqobuz
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: getStreamUrl took 488 milliseconds
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3188743&eid=70054350&fmt=6&profile=raw&app_id=539451548&cid=2368744&etsp=1774607175&hmac=hZhsStxeerfqSRH2aWZeeoBJwZw
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got range request: bytes=15774684-
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Requesting upstream with range: bytes=15774684-
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream status code: 206
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Client closed connection
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Handling url /?data=qobuz://song/70054350
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream closed. Received 36202 bytes
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Incomplete transfer. Expected 126504665, got 36202
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Retrying with range: bytes=15810886- (attempt 1)
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint getStreamUrlqobuz
Mar 27 20:26:15 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resuming with range: bytes=71191871-
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: getStreamUrl took 505 milliseconds
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3188743&eid=70054350&fmt=6&profile=raw&app_id=539451548&cid=2368744&etsp=1774607176&hmac=bONuJHAJ9ZBb1nKeJCv1SvDDTF4
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Got range request: bytes=15768991-
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Requesting upstream with range: bytes=15768991-
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resume upstream status code: 206
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Upstream status code: 206
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: error: null
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info:
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: ---------------------------- MPD announces state update: player
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::getState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand status
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand status took 1 milliseconds
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: verbose: ControllerMpd::parseTrackInfo
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: ControllerMpd::pushState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::servicePushState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CorePlayQueue::getTrack 0
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: verbose: STATE SERVICE {"status":"play","position":0,"seek":170000,"duration":1401,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"739 Kbps","isStreaming":false,"title":"70054350","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/70054350","trackType":"qobuz"}
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: verbose: CURRENT POSITION 0
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState stateService play
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::syncState currentStatus play
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: Received an update from plugin. extracting info from payload
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreStateMachine::pushState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioPushState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::volumioGetState
Mar 27 20:26:16 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:16.489+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=171254 volume=100
Mar 27 20:26:16 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:16.490+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/70054350 title="Angel Dust"
Mar 27 20:26:16 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:16.492+11:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" state=STATUS_PLAYING positionMs=171254 volume=100
Mar 27 20:26:16 du-bon-son-chez-berthet volumio5-onboarding[1276]: time=2026-03-27T20:26:16.492+11:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.82:58568,00:00:00:00:00:00%01 @ 0x2dc10b0" id=qobuz://song/70054350 title="Angel Dust"
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: info: ------------------------------ 22ms
Mar 27 20:26:16 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resuming with range: bytes=15810886-
Mar 27 20:26:17 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resume upstream status code: 206
Mar 27 20:26:18 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri
Mar 27 20:26:20 du-bon-son-chez-berthet volumio[1043]: info: handleBrowseUri took 1154 milliseconds
Mar 27 20:26:20 du-bon-son-chez-berthet volumio[1043]: info: Preload queue cleared
Mar 27 20:26:20 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint getSimilarArtists
Mar 27 20:26:20 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists
Mar 27 20:26:20 du-bon-son-chez-berthet volumio[1043]: info: Executing endpoint metavolumio
Mar 27 20:26:20 du-bon-son-chez-berthet volumio[1043]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 27 20:26:21 du-bon-son-chez-berthet volumio[1043]: STREAMING PROXY: Resume ended. Received 142263693 bytes
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: TypeError: Cannot read property 'slice' of null
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at Object.onceWrapper (events.js:422:26)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at ClientRequest.emit (events.js:315:20)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at TLSSocket.socketOnData (_http_client.js:509:22)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at TLSSocket.emit (events.js:315:20)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at addChunk (internal/streams/readable.js:309:12)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at readableAddChunk (internal/streams/readable.js:284:9)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at TLSSocket.Readable.push (internal/streams/readable.js:223:10)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23)
Mar 27 20:26:23 du-bon-son-chez-berthet volumio[1043]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 27 20:26:23 du-bon-son-chez-berthet sudo[2904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-27 20:25
Mar 27 20:26:23 du-bon-son-chez-berthet sudo[2904]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET"
VOLUMIO_VERSION="3.912"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"