-- Logs begin at Sun 2026-02-15 04:25:02 CET, end at Mon 2026-02-16 22:47:47 CET. -- Feb 16 22:47:32 volumio volumio[856]: info: CorePlayQueue::getTrack 124 Feb 16 22:47:32 volumio volumio[856]: info: CorePlayQueue::getTrack 191 Feb 16 22:47:32 volumio volumio[856]: info: Prefetching next song Feb 16 22:47:32 volumio volumio[856]: info: [1771278452117] ControllerQobuz::prefetch Feb 16 22:47:32 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/5162342" Feb 16 22:47:32 volumio volumio[856]: STREAMING PROXY: Handling url /?data=qobuz://song/5162342 Feb 16 22:47:32 volumio volumio[856]: info: Executing endpoint getStreamUrlqobuz Feb 16 22:47:32 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 16 22:47:32 volumio volumio[856]: info: getStreamUrl took 172 milliseconds Feb 16 22:47:32 volumio volumio[856]: error: Could not get QOBUZ Stream URL: [object Object] Feb 16 22:47:32 volumio volumio[856]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get QOBUZ Stream URL: [object Object]"} Feb 16 22:47:32 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/5162342" Feb 16 22:47:32 volumio volumio[856]: info: Feb 16 22:47:32 volumio volumio[856]: ---------------------------- MPD announces system playlist update Feb 16 22:47:32 volumio volumio[856]: info: Ignoring MPD Status Update Feb 16 22:47:32 volumio volumio[856]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/5162342" took 2 milliseconds Feb 16 22:47:32 volumio volumio[856]: STREAMING PROXY: Handling url /?data=qobuz://song/5162342 Feb 16 22:47:32 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 16 22:47:32 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand consume 1 Feb 16 22:47:32 volumio volumio[856]: info: ------------------------------ 3ms Feb 16 22:47:32 volumio volumio[856]: info: sendMpdCommand consume 1 took 1 milliseconds Feb 16 22:47:32 volumio volumio[856]: info: Executing endpoint getStreamUrlqobuz Feb 16 22:47:32 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 16 22:47:32 volumio volumio[856]: info: getStreamUrl took 141 milliseconds Feb 16 22:47:32 volumio volumio[856]: error: Could not get QOBUZ Stream URL: [object Object] Feb 16 22:47:32 volumio volumio[856]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get QOBUZ Stream URL: [object Object]"} Feb 16 22:47:36 volumio volumio[856]: info: CoreStateMachine::startPlaybackTimer Feb 16 22:47:36 volumio volumio[856]: info: CorePlayQueue::getTrack 191 Feb 16 22:47:37 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:37 volumio volumio[856]: info: CorePlayQueue::getTrack 191 Feb 16 22:47:37 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:37 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:37 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:37 volumio volumio[856]: info: CorePlayQueue::getTrack 191 Feb 16 22:47:37 volumio volumio[856]: info: [LastFM] Current track has sufficient metadata: title (I didn't know) and artist (Tristesse Contemporaine) passed on explicitly Feb 16 22:47:37 volumio volumio[856]: info: Feb 16 22:47:37 volumio volumio[856]: ---------------------------- MPD announces system playlist update Feb 16 22:47:37 volumio volumio[856]: info: Ignoring MPD Status Update Feb 16 22:47:37 volumio volumio[856]: STREAMING PROXY: Handling url /?data=qobuz://song/5162342 Feb 16 22:47:37 volumio volumio[856]: info: ------------------------------ 1ms Feb 16 22:47:37 volumio volumio[856]: info: Executing endpoint getStreamUrlqobuz Feb 16 22:47:37 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 16 22:47:38 volumio volumio[856]: info: getStreamUrl took 273 milliseconds Feb 16 22:47:38 volumio volumio[856]: error: Could not get QOBUZ Stream URL: [object Object] Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get QOBUZ Stream URL: [object Object]"} Feb 16 22:47:38 volumio volumio[856]: info: Feb 16 22:47:38 volumio volumio[856]: ---------------------------- MPD announces state update: player Feb 16 22:47:38 volumio volumio[856]: info: ControllerMpd::getState Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand status Feb 16 22:47:38 volumio volumio[856]: error: MPD returned error for command status: Failed to decode http://127.0.0.1:3245?data=qobuz://song/5162342; got HTTP status 404 Feb 16 22:47:38 volumio volumio[856]: error: MPD Playback Error: Failed to decode stream, moving to next track Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand status took 3 milliseconds Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::parseState Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand clearerror took 2 milliseconds Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::parseTrackInfo Feb 16 22:47:38 volumio volumio[856]: info: ControllerMpd::pushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::servicePushState Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 191 Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 191 Feb 16 22:47:38 volumio volumio[856]: 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":"5162342","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/5162342","trackType":"qobuz"} Feb 16 22:47:38 volumio volumio[856]: verbose: CURRENT POSITION 191 Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::syncState stateService stop Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::syncState currentStatus play Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::play index undefined Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::startPlaybackTimer Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: info: [1771278458145] ControllerQobuz::clearAddPlayTrack Feb 16 22:47:38 volumio volumio[856]: info: ------------------------------ 16ms Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand stop Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand stop took 16 milliseconds Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand clear Feb 16 22:47:38 volumio volumio[856]: info: Feb 16 22:47:38 volumio volumio[856]: ---------------------------- MPD announces system playlist update Feb 16 22:47:38 volumio volumio[856]: info: Ignoring MPD Status Update Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand clear took 5 milliseconds Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/329407003" Feb 16 22:47:38 volumio volumio[856]: error: updateQueue error: null Feb 16 22:47:38 volumio volumio[856]: info: ------------------------------ 2ms Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Handling url /?data=qobuz://song/329407003 Feb 16 22:47:38 volumio volumio[856]: info: Executing endpoint getStreamUrlqobuz Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 16 22:47:38 volumio volumio[856]: info: getStreamUrl took 200 milliseconds Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1581749&eid=329407003&fmt=7&profile=raw&app_id=539451548&cid=2067625&etsp=1771282058&hmac=0o5eMO-jtV1eex4Vjeleh4fNEws Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Requesting upstream with range: none Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Upstream status code: 200 Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/329407003" Feb 16 22:47:38 volumio volumio[856]: info: Feb 16 22:47:38 volumio volumio[856]: ---------------------------- MPD announces system playlist update Feb 16 22:47:38 volumio volumio[856]: info: Ignoring MPD Status Update Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/329407003" took 2 milliseconds Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand play Feb 16 22:47:38 volumio volumio[856]: info: ------------------------------ 3ms Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand play took 2 milliseconds Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Client closed connection Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Upstream closed. Received 50662 bytes Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Incomplete transfer. Expected 37755238, got 50662 Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Retrying with range: bytes=50662- (attempt 1) Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Handling url /?data=qobuz://song/329407003 Feb 16 22:47:38 volumio volumio[856]: info: Executing endpoint getStreamUrlqobuz Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 16 22:47:38 volumio volumio[856]: info: getStreamUrl took 233 milliseconds Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1581749&eid=329407003&fmt=7&profile=raw&app_id=539451548&cid=2067625&etsp=1771282058&hmac=0o5eMO-jtV1eex4Vjeleh4fNEws Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Requesting upstream with range: none Feb 16 22:47:38 volumio volumio[856]: STREAMING PROXY: Upstream status code: 200 Feb 16 22:47:38 volumio volumio[856]: info: Feb 16 22:47:38 volumio volumio[856]: ---------------------------- MPD announces state update: player Feb 16 22:47:38 volumio volumio[856]: info: ControllerMpd::getState Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand status Feb 16 22:47:38 volumio volumio[856]: info: Feb 16 22:47:38 volumio volumio[856]: ---------------------------- MPD announces state update: player Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand status took 5 milliseconds Feb 16 22:47:38 volumio volumio[856]: info: ControllerMpd::getState Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand status Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::parseState Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand status took 2 milliseconds Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::parseState Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::parseTrackInfo Feb 16 22:47:38 volumio volumio[856]: info: ControllerMpd::pushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::servicePushState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":183,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"329407003","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/329407003","trackType":"qobuz"} Feb 16 22:47:38 volumio volumio[856]: verbose: CURRENT POSITION 50 Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::syncState stateService play Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::syncState currentStatus stop Feb 16 22:47:38 volumio volumio[856]: info: ------------------------------ 12ms Feb 16 22:47:38 volumio volumio[856]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 16 22:47:38 volumio volumio[856]: verbose: ControllerMpd::parseTrackInfo Feb 16 22:47:38 volumio volumio[856]: info: ControllerMpd::pushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::servicePushState Feb 16 22:47:38 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:38 volumio volumio[856]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":183,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"329407003","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/329407003","trackType":"qobuz"} Feb 16 22:47:38 volumio volumio[856]: verbose: CURRENT POSITION 50 Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::syncState stateService play Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::syncState currentStatus play Feb 16 22:47:38 volumio volumio[856]: info: Received an update from plugin. extracting info from payload Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:38 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:38 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:38 volumio volumio[856]: info: ------------------------------ 22ms Feb 16 22:47:38 volumio volumio[856]: info: [LastFM] Current track has sufficient metadata: title (Plant the Seed) and artist (The Slow Readers Club) passed on explicitly Feb 16 22:47:39 volumio volumio[856]: info: Moving to next track after playback error Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::volumioPlay Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::play index 57 Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::stop Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::stPlaybackTimer Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::updateTrackBlock Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrackBlock Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::serviceStop Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrack 50 Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::serviceStop Feb 16 22:47:39 volumio volumio[856]: info: [1771278459143] ControllerQobuz::stop Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 16 22:47:39 volumio volumio[856]: info: ControllerMpd::stop Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand stop Feb 16 22:47:39 volumio volumio[856]: info: Feb 16 22:47:39 volumio volumio[856]: ---------------------------- MPD announces state update: player Feb 16 22:47:39 volumio volumio[856]: info: sendMpdCommand stop took 15 milliseconds Feb 16 22:47:39 volumio volumio[856]: info: ControllerMpd::getState Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand status Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::play index undefined Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrack 57 Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::startPlaybackTimer Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrack 57 Feb 16 22:47:39 volumio volumio[856]: info: [1771278459161] ControllerQobuz::clearAddPlayTrack Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand stop Feb 16 22:47:39 volumio volumio[856]: info: sendMpdCommand status took 3 milliseconds Feb 16 22:47:39 volumio volumio[856]: info: sendMpdCommand stop took 2 milliseconds Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::parseState Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand clear Feb 16 22:47:39 volumio volumio[856]: info: Feb 16 22:47:39 volumio volumio[856]: ---------------------------- MPD announces system playlist update Feb 16 22:47:39 volumio volumio[856]: info: Ignoring MPD Status Update Feb 16 22:47:39 volumio volumio[856]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 16 22:47:39 volumio volumio[856]: info: sendMpdCommand clear took 2 milliseconds Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::parseTrackInfo Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/27988913" Feb 16 22:47:39 volumio volumio[856]: info: ControllerMpd::pushState Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::servicePushState Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrack 57 Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:39 volumio volumio[856]: info: CorePlayQueue::getTrack 57 Feb 16 22:47:39 volumio volumio[856]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 16 22:47:39 volumio volumio[856]: info: ------------------------------ 17ms Feb 16 22:47:39 volumio volumio[856]: error: updateQueue error: null Feb 16 22:47:39 volumio volumio[856]: info: ------------------------------ 11ms Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Client closed connection Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Upstream closed. Received 4049270 bytes Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Incomplete transfer. Expected 37755238, got 4049270 Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Retrying with range: bytes=4049270- (attempt 1) Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Handling url /?data=qobuz://song/27988913 Feb 16 22:47:39 volumio volumio[856]: info: Executing endpoint getStreamUrlqobuz Feb 16 22:47:39 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 16 22:47:39 volumio volumio[856]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Plant the Seed","mbid":"2a7d7870-4de2-46dd-81d2-4b997c8e5da4","url":"https://www.last.fm/music/The+Slow+Readers+Club/_/Plant+the+Seed","duration":"183000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"19430","playcount":"98785","artist":{"name":"The Slow Readers Club","mbid":"ce9e077c-30cd-47ca-9475-2d5bb99d8da0","url":"https://www.last.fm/music/The+Slow+Readers+Club"},"album":{"artist":"The Slow Readers Club","title":"Cavalcade","url":"https://www.last.fm/music/The+Slow+Readers+Club/Cavalcade","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/cadb1bbff7a54a2322d5cb2b1230fa0c.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/cadb1bbff7a54a2322d5cb2b1230fa0c.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/cadb1bbff7a54a2322d5cb2b1230fa0c.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/cadb1bbff7a54a2322d5cb2b1230fa0c.png","@":{"size":"extralarge"}}]},"userplaycount":"8","userloved":"0","toptags":""}} Feb 16 22:47:39 volumio volumio[856]: info: getStreamUrl took 177 milliseconds Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1581749&eid=27988913&fmt=7&profile=raw&app_id=539451548&cid=2067625&etsp=1771282059&hmac=PUYZaiz1UoQimRdXCGdTOxgigus Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Requesting upstream with range: none Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Resuming with range: bytes=50662- Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Resume upstream status code: 206 Feb 16 22:47:39 volumio volumio[856]: STREAMING PROXY: Upstream status code: 200 Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/27988913" Feb 16 22:47:39 volumio volumio[856]: info: Feb 16 22:47:39 volumio volumio[856]: ---------------------------- MPD announces system playlist update Feb 16 22:47:39 volumio volumio[856]: info: Ignoring MPD Status Update Feb 16 22:47:39 volumio volumio[856]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/27988913" took 2 milliseconds Feb 16 22:47:39 volumio volumio[856]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 16 22:47:39 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand play Feb 16 22:47:39 volumio volumio[856]: info: ------------------------------ 3ms Feb 16 22:47:39 volumio volumio[856]: info: sendMpdCommand play took 1 milliseconds Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Handling url /?data=qobuz://song/27988913 Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Client closed connection Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Upstream closed. Received 34891 bytes Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Incomplete transfer. Expected 45065091, got 34891 Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Retrying with range: bytes=34891- (attempt 1) Feb 16 22:47:40 volumio volumio[856]: info: Executing endpoint getStreamUrlqobuz Feb 16 22:47:40 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Resuming with range: bytes=4049270- Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Resume upstream status code: 206 Feb 16 22:47:40 volumio volumio[856]: info: getStreamUrl took 418 milliseconds Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1581749&eid=27988913&fmt=7&profile=raw&app_id=539451548&cid=2067625&etsp=1771282060&hmac=pIuwaHtoWcWh-BsFIaZ_LRj-63A Feb 16 22:47:40 volumio volumio[856]: STREAMING PROXY: Requesting upstream with range: none Feb 16 22:47:40 volumio nmbd[775]: [2026/02/16 22:47:40.715079, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 16 22:47:40 volumio nmbd[775]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.2.103 for name WORKGROUP<1d>. Feb 16 22:47:40 volumio nmbd[775]: This response was from IP 192.168.2.104, reporting an IP address of 192.168.2.104. Feb 16 22:47:41 volumio volumio[856]: STREAMING PROXY: Resuming with range: bytes=34891- Feb 16 22:47:41 volumio volumio[856]: STREAMING PROXY: Resume upstream status code: 206 Feb 16 22:47:41 volumio volumio[856]: STREAMING PROXY: Upstream status code: 200 Feb 16 22:47:41 volumio volumio[856]: info: Feb 16 22:47:41 volumio volumio[856]: ---------------------------- MPD announces state update: player Feb 16 22:47:41 volumio volumio[856]: info: ControllerMpd::getState Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand status Feb 16 22:47:41 volumio volumio[856]: info: Feb 16 22:47:41 volumio volumio[856]: ---------------------------- MPD announces state update: player Feb 16 22:47:41 volumio volumio[856]: info: sendMpdCommand status took 4 milliseconds Feb 16 22:47:41 volumio volumio[856]: info: ControllerMpd::getState Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand status Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::parseState Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 16 22:47:41 volumio volumio[856]: info: sendMpdCommand status took 2 milliseconds Feb 16 22:47:41 volumio volumio[856]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::parseState Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::parseTrackInfo Feb 16 22:47:41 volumio volumio[856]: info: ControllerMpd::pushState Feb 16 22:47:41 volumio volumio[856]: info: CoreCommandRouter::servicePushState Feb 16 22:47:41 volumio volumio[856]: info: CorePlayQueue::getTrack 57 Feb 16 22:47:41 volumio volumio[856]: 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":"27988913","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/27988913","trackType":"qobuz"} Feb 16 22:47:41 volumio volumio[856]: verbose: CURRENT POSITION 57 Feb 16 22:47:41 volumio volumio[856]: info: CoreStateMachine::syncState stateService play Feb 16 22:47:41 volumio volumio[856]: info: CoreStateMachine::syncState currentStatus stop Feb 16 22:47:41 volumio volumio[856]: info: ------------------------------ 11ms Feb 16 22:47:41 volumio volumio[856]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 16 22:47:41 volumio volumio[856]: verbose: ControllerMpd::parseTrackInfo Feb 16 22:47:41 volumio volumio[856]: info: ControllerMpd::pushState Feb 16 22:47:41 volumio volumio[856]: info: CoreCommandRouter::servicePushState Feb 16 22:47:41 volumio volumio[856]: info: CorePlayQueue::getTrack 57 Feb 16 22:47:41 volumio volumio[856]: 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":"27988913","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/27988913","trackType":"qobuz"} Feb 16 22:47:41 volumio volumio[856]: verbose: CURRENT POSITION 57 Feb 16 22:47:41 volumio volumio[856]: info: CoreStateMachine::syncState stateService play Feb 16 22:47:41 volumio volumio[856]: info: CoreStateMachine::syncState currentStatus play Feb 16 22:47:41 volumio volumio[856]: info: Received an update from plugin. extracting info from payload Feb 16 22:47:41 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:41 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 22:47:41 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:41 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:41 volumio volumio[856]: info: CoreStateMachine::pushState Feb 16 22:47:41 volumio volumio[856]: info: CoreCommandRouter::volumioPushState Feb 16 22:47:41 volumio volumio[856]: info: CoreCommandRouter::volumioGetState Feb 16 22:47:41 volumio volumio[856]: info: ------------------------------ 21ms Feb 16 22:47:41 volumio volumio[856]: info: [LastFM] Current track has sufficient metadata: title (Started Right) and artist (Hot Chip) passed on explicitly Feb 16 22:47:41 volumio volumio[856]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Started Right","mbid":"62ef8df2-cbba-46fb-bc2c-e27c53855c19","url":"https://www.last.fm/music/Hot+Chip/_/Started+Right","duration":"223000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"51533","playcount":"213594","artist":{"name":"Hot Chip","mbid":"d8915e13-d67a-4aa0-9c0b-1f126af951af","url":"https://www.last.fm/music/Hot+Chip"},"album":{"artist":"Hot Chip","title":"Why Make Sense?","url":"https://www.last.fm/music/Hot+Chip/Why+Make+Sense%3F","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/d70dcff347a0409cc03f591f04cba3b3.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/d70dcff347a0409cc03f591f04cba3b3.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/d70dcff347a0409cc03f591f04cba3b3.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/d70dcff347a0409cc03f591f04cba3b3.png","@":{"size":"extralarge"}}]},"userplaycount":"13","userloved":"0","toptags":""}} Feb 16 22:47:46 volumio volumio[856]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 16 22:47:46 volumio volumio[856]: TypeError: Cannot read property '@' of undefined Feb 16 22:47:46 volumio volumio[856]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Feb 16 22:47:46 volumio volumio[856]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Feb 16 22:47:46 volumio volumio[856]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:308:18) Feb 16 22:47:46 volumio volumio[856]: at Parser.emit (events.js:315:20) Feb 16 22:47:46 volumio volumio[856]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:123:26) Feb 16 22:47:46 volumio volumio[856]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:624:35) Feb 16 22:47:46 volumio volumio[856]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:653:5) Feb 16 22:47:46 volumio volumio[856]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:677:7) Feb 16 22:47:46 volumio volumio[856]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:871:9) Feb 16 22:47:46 volumio volumio[856]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1436:13) Feb 16 22:47:46 volumio volumio[856]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:323:31) Feb 16 22:47:46 volumio volumio[856]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Feb 16 22:47:46 volumio volumio[856]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Feb 16 22:47:46 volumio volumio[856]: at IncomingMessage.emit (events.js:327:22) Feb 16 22:47:46 volumio volumio[856]: at endReadableNT (internal/streams/readable.js:1327:12) Feb 16 22:47:46 volumio volumio[856]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Feb 16 22:47:46 volumio volumio[856]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 16 22:47:47 volumio sudo[31198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-16 22:46 Feb 16 22:47:47 volumio sudo[31198]: 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="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 01:46:18 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3e9dbaf8f44792d26e97456a18f12823"