-- Logs begin at Thu 2019-02-14 18:11:59 PST, end at Wed 2026-01-28 16:55:10 PST. -- Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::volumioPlay Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::play index 207 Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::stop Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::updateTrackBlock Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrackBlock Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::stPlaybackTimer Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::pushState Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 126 Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::volumioPushState Jan 28 16:54:02 volumio volumio[1091]: info: MRS: Pushing multiroomSync output update for this device Jan 28 16:54:02 volumio volumio[1091]: info: MRS: Pushing multiroomSync output Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::volumioGetState Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 126 Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::serviceStop Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 126 Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::serviceStop Jan 28 16:54:02 volumio volumio[1091]: info: [1769590442081] ControllerQobuz::stop Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 28 16:54:02 volumio volumio[1091]: info: ControllerMpd::stop Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 16:54:02 volumio volumio[1091]: STREAMING PROXY: Client dropped request, destroying Jan 28 16:54:02 volumio volumio[1091]: info: Jan 28 16:54:02 volumio volumio[1091]: ---------------------------- MPD announces state update: player Jan 28 16:54:02 volumio volumio[1091]: info: sendMpdCommand stop took 20 milliseconds Jan 28 16:54:02 volumio volumio[1091]: info: ControllerMpd::getState Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand status Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::play index undefined Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 207 Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::startPlaybackTimer Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 207 Jan 28 16:54:02 volumio volumio[1091]: info: [1769590442107] ControllerQobuz::clearAddPlayTrack Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 16:54:02 volumio volumio[1091]: info: sendMpdCommand status took 6 milliseconds Jan 28 16:54:02 volumio volumio[1091]: info: sendMpdCommand stop took 3 milliseconds Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::parseState Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 16:54:02 volumio volumio[1091]: info: Jan 28 16:54:02 volumio volumio[1091]: ---------------------------- MPD announces system playlist update Jan 28 16:54:02 volumio volumio[1091]: info: Ignoring MPD Status Update Jan 28 16:54:02 volumio volumio[1091]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 28 16:54:02 volumio volumio[1091]: info: sendMpdCommand clear took 2 milliseconds Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::parseTrackInfo Jan 28 16:54:02 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/458302" Jan 28 16:54:02 volumio volumio[1091]: info: ControllerMpd::pushState Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::servicePushState Jan 28 16:54:02 volumio volumio[1091]: info: CoreStateMachine::pushState Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 207 Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::volumioPushState Jan 28 16:54:02 volumio volumio[1091]: info: MRS: Pushing multiroomSync output update for this device Jan 28 16:54:02 volumio volumio[1091]: info: MRS: Pushing multiroomSync output Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::volumioGetState Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 207 Jan 28 16:54:02 volumio volumio[1091]: info: CorePlayQueue::getTrack 207 Jan 28 16:54:02 volumio volumio[1091]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jan 28 16:54:02 volumio volumio[1091]: STREAMING PROXY: Handling url /?data=qobuz://song/458302 Jan 28 16:54:02 volumio volumio[1091]: info: ------------------------------ 30ms Jan 28 16:54:02 volumio volumio[1091]: error: updateQueue error: null Jan 28 16:54:02 volumio volumio[1091]: info: ------------------------------ 19ms Jan 28 16:54:02 volumio volumio[1091]: info: Executing endpoint getStreamUrlqobuz Jan 28 16:54:02 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 28 16:54:03 volumio volumio[1091]: info: getStreamUrl took 964 milliseconds Jan 28 16:54:03 volumio volumio[1091]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2831570&eid=458302&fmt=6&profile=raw&app_id=539451548&cid=3699798&etsp=1769594042&hmac=GHZY77zcTEOMbHsEwMqT_3Q30w4 Jan 28 16:54:03 volumio volumio[1091]: STREAMING PROXY: Response: 200, length: 32004259 Jan 28 16:54:03 volumio volumio[1091]: STREAMING PROXY: Client dropped request, destroying Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/458302" Jan 28 16:54:03 volumio volumio[1091]: info: Jan 28 16:54:03 volumio volumio[1091]: ---------------------------- MPD announces system playlist update Jan 28 16:54:03 volumio volumio[1091]: info: Ignoring MPD Status Update Jan 28 16:54:03 volumio volumio[1091]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/458302" took 1 milliseconds Jan 28 16:54:03 volumio volumio[1091]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand play Jan 28 16:54:03 volumio volumio[1091]: info: ------------------------------ 2ms Jan 28 16:54:03 volumio volumio[1091]: info: sendMpdCommand play took 2 milliseconds Jan 28 16:54:03 volumio volumio[1091]: STREAMING PROXY: Handling url /?data=qobuz://song/458302 Jan 28 16:54:03 volumio volumio[1091]: info: Executing endpoint getStreamUrlqobuz Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 28 16:54:03 volumio volumio[1091]: info: getStreamUrl took 490 milliseconds Jan 28 16:54:03 volumio volumio[1091]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2831570&eid=458302&fmt=6&profile=raw&app_id=539451548&cid=3699798&etsp=1769594043&hmac=2UfEvPgphS-TCcIJryntVweANLw Jan 28 16:54:03 volumio volumio[1091]: STREAMING PROXY: Response: 200, length: 32004259 Jan 28 16:54:03 volumio volumio[1091]: info: Jan 28 16:54:03 volumio volumio[1091]: ---------------------------- MPD announces state update: player Jan 28 16:54:03 volumio volumio[1091]: info: ControllerMpd::getState Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand status Jan 28 16:54:03 volumio volumio[1091]: info: Jan 28 16:54:03 volumio volumio[1091]: ---------------------------- MPD announces state update: player Jan 28 16:54:03 volumio kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Jan 28 16:54:03 volumio volumio[1091]: info: sendMpdCommand status took 3 milliseconds Jan 28 16:54:03 volumio volumio[1091]: info: ControllerMpd::getState Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand status Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::parseState Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 16:54:03 volumio volumio[1091]: info: sendMpdCommand status took 5 milliseconds Jan 28 16:54:03 volumio volumio[1091]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::parseState Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::parseTrackInfo Jan 28 16:54:03 volumio volumio[1091]: info: ControllerMpd::pushState Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::servicePushState Jan 28 16:54:03 volumio volumio[1091]: info: CorePlayQueue::getTrack 207 Jan 28 16:54:03 volumio volumio[1091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":325,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"458302","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/458302","trackType":"qobuz"} Jan 28 16:54:03 volumio volumio[1091]: verbose: CURRENT POSITION 207 Jan 28 16:54:03 volumio volumio[1091]: info: CoreStateMachine::syncState stateService play Jan 28 16:54:03 volumio volumio[1091]: info: CoreStateMachine::syncState currentStatus stop Jan 28 16:54:03 volumio volumio[1091]: info: ------------------------------ 15ms Jan 28 16:54:03 volumio volumio[1091]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 28 16:54:03 volumio volumio[1091]: verbose: ControllerMpd::parseTrackInfo Jan 28 16:54:03 volumio volumio[1091]: info: ControllerMpd::pushState Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::servicePushState Jan 28 16:54:03 volumio volumio[1091]: info: CorePlayQueue::getTrack 207 Jan 28 16:54:03 volumio volumio[1091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":325,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"458302","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/458302","trackType":"qobuz"} Jan 28 16:54:03 volumio volumio[1091]: verbose: CURRENT POSITION 207 Jan 28 16:54:03 volumio volumio[1091]: info: CoreStateMachine::syncState stateService play Jan 28 16:54:03 volumio volumio[1091]: info: CoreStateMachine::syncState currentStatus play Jan 28 16:54:03 volumio volumio[1091]: info: Received an update from plugin. extracting info from payload Jan 28 16:54:03 volumio volumio[1091]: info: CoreStateMachine::pushState Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::volumioPushState Jan 28 16:54:03 volumio volumio[1091]: info: MRS: Pushing multiroomSync output update for this device Jan 28 16:54:03 volumio volumio[1091]: info: MRS: Pushing multiroomSync output Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::volumioGetState Jan 28 16:54:03 volumio volumio[1091]: info: CoreStateMachine::pushState Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::volumioPushState Jan 28 16:54:03 volumio volumio[1091]: info: MRS: Pushing multiroomSync output update for this device Jan 28 16:54:03 volumio volumio[1091]: info: MRS: Pushing multiroomSync output Jan 28 16:54:03 volumio volumio[1091]: info: CoreCommandRouter::volumioGetState Jan 28 16:54:03 volumio volumio[1091]: info: ------------------------------ 57ms Jan 28 16:54:15 volumio volumio[1091]: STREAMING PROXY: Client dropped request, destroying Jan 28 16:54:34 volumio volumio[1091]: info: CoreCommandRouter::volumioGetState Jan 28 16:54:36 volumio volumio[1091]: info: Executing endpoint metavolumio Jan 28 16:54:36 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 28 16:54:36 volumio volumio[1091]: info: Executing endpoint metavolumio Jan 28 16:54:36 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 28 16:54:36 volumio volumio[1091]: info: Executing endpoint metavolumio Jan 28 16:54:36 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 28 16:54:43 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 28 16:54:43 volumio volumio[1091]: info: CURURI: playlists/Qobuz Jan 28 16:54:43 volumio volumio[1091]: info: Preload queue cleared Jan 28 16:54:43 volumio volumio[1091]: info: Preloading song: qobuz://song/2020929 Jan 28 16:54:43 volumio volumio[1091]: info: Preloading song: qobuz://song/106960154 Jan 28 16:54:43 volumio volumio[1091]: info: Preloading song: qobuz://song/54502944 Jan 28 16:54:43 volumio volumio[1091]: info: Exploding uri qobuz://song/2020929 in service qobuz Jan 28 16:54:43 volumio volumio[1091]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 28 16:54:44 volumio volumio[1091]: info: Exploding uri qobuz://song/106960154 in service qobuz Jan 28 16:54:44 volumio volumio[1091]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 28 16:54:44 volumio volumio[1091]: info: Exploding uri qobuz://song/54502944 in service qobuz Jan 28 16:54:44 volumio volumio[1091]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 28 16:54:45 volumio volumio[1091]: info: explodeUri took 1054 milliseconds Jan 28 16:54:45 volumio volumio[1091]: error: QOBUZ Browse Error: failed to get track: got 404: {"status":"error","code":404,"message":"No result matching given argument"} Jan 28 16:54:45 volumio volumio[1091]: error: Commandrouter: Cannot explode uri qobuz://song/2020929 from service qobuz: failed to get track: got 404: {"status":"error","code":404,"message":"No result matching given argument"} Jan 28 16:54:45 volumio volumio[1091]: info: explodeUri took 959 milliseconds Jan 28 16:54:45 volumio volumio[1091]: error: QOBUZ Browse Error: failed to get track: got 404: {"status":"error","code":404,"message":"No result matching given argument"} Jan 28 16:54:45 volumio volumio[1091]: error: Commandrouter: Cannot explode uri qobuz://song/54502944 from service qobuz: failed to get track: got 404: {"status":"error","code":404,"message":"No result matching given argument"} Jan 28 16:54:45 volumio volumio[1091]: info: explodeUri took 1263 milliseconds Jan 28 16:54:45 volumio volumio[1091]: error: QOBUZ Browse Error: failed to get track: got 404: {"status":"error","code":404,"message":"No result matching given argument"} Jan 28 16:54:45 volumio volumio[1091]: error: Commandrouter: Cannot explode uri qobuz://song/106960154 from service qobuz: failed to get track: got 404: {"status":"error","code":404,"message":"No result matching given argument"} Jan 28 16:54:51 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 28 16:54:51 volumio volumio[1091]: info: handleBrowseUri took 260 milliseconds Jan 28 16:54:51 volumio volumio[1091]: info: Preload queue cleared Jan 28 16:54:51 volumio volumio[1091]: info: Preload queue cleared Jan 28 16:54:55 volumio volumio[1091]: Searching plugin music_service/qobuz Jan 28 16:54:55 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 16:54:56 volumio volumio[1091]: Searching plugin music_service/qobuz Jan 28 16:54:56 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 16:54:57 volumio volumio[1091]: info: searchQOBUZUri took 1885 milliseconds Jan 28 16:54:57 volumio volumio[1091]: info: All search sources collected, pushing search results Jan 28 16:54:58 volumio volumio[1091]: info: searchQOBUZUri took 2017 milliseconds Jan 28 16:54:58 volumio volumio[1091]: info: All search sources collected, pushing search results Jan 28 16:55:04 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 28 16:55:06 volumio volumio[1091]: info: handleBrowseUri took 1823 milliseconds Jan 28 16:55:06 volumio volumio[1091]: info: Preload queue cleared Jan 28 16:55:06 volumio volumio[1091]: info: Executing endpoint getSimilarArtists Jan 28 16:55:06 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jan 28 16:55:06 volumio volumio[1091]: info: Executing endpoint getSimilarArtists Jan 28 16:55:06 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jan 28 16:55:06 volumio volumio[1091]: info: Executing endpoint getSimilarArtists Jan 28 16:55:06 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jan 28 16:55:07 volumio volumio[1091]: info: Executing endpoint metavolumio Jan 28 16:55:07 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 28 16:55:07 volumio volumio[1091]: info: Executing endpoint metavolumio Jan 28 16:55:07 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 28 16:55:07 volumio volumio[1091]: info: Executing endpoint metavolumio Jan 28 16:55:07 volumio volumio[1091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 28 16:55:09 volumio volumio[1091]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:55:09 volumio volumio[1091]: Error: connect ECONNREFUSED 158.69.209.125:443 Jan 28 16:55:09 volumio volumio[1091]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Jan 28 16:55:09 volumio volumio[1091]: errno: -111, Jan 28 16:55:09 volumio volumio[1091]: code: 'ECONNREFUSED', Jan 28 16:55:09 volumio volumio[1091]: syscall: 'connect', Jan 28 16:55:09 volumio volumio[1091]: address: '158.69.209.125', Jan 28 16:55:09 volumio volumio[1091]: port: 443 Jan 28 16:55:09 volumio volumio[1091]: } Jan 28 16:55:09 volumio volumio[1091]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:55:10 volumio sudo[3824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-28 16:54 Jan 28 16:55:10 volumio sudo[3824]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"