-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sat 2026-04-11 17:00:33 CEST. -- Apr 11 16:59:02 pecanpiplus volumio[827]: STREAMING PROXY: Upstream closed. Received 36493800 bytes Apr 11 16:59:02 pecanpiplus volumio[827]: STREAMING PROXY: Upstream closed. Received 36493800 bytes Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 16:59:05 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::stPlaybackTimer Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::servicePause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePause Apr 11 16:59:15 pecanpiplus volumio[827]: info: [1775919555020] ControllerTidal::pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 16:59:15 pecanpiplus volumio[827]: info: ControllerMpd::pause Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: sendMpdCommand pause took 2 milliseconds Apr 11 16:59:15 pecanpiplus volumio[827]: info: Apr 11 16:59:15 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:15 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:15 pecanpiplus volumio[827]: info: Apr 11 16:59:15 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:15 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:15 pecanpiplus volumio[827]: info: Apr 11 16:59:15 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:15 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:15 pecanpiplus volumio[827]: info: sendMpdCommand status took 4 milliseconds Apr 11 16:59:15 pecanpiplus volumio[827]: info: sendMpdCommand status took 3 milliseconds Apr 11 16:59:15 pecanpiplus volumio[827]: info: sendMpdCommand status took 1 milliseconds Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:15 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 16:59:15 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 11 16:59:15 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:15 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":23200,"duration":364,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"405 Kbps","isStreaming":false,"title":"1887380&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887380&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: CURRENT POSITION 1 Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:15 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::stPlaybackTimer Apr 11 16:59:15 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":23200,"duration":364,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"405 Kbps","isStreaming":false,"title":"1887380&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887380&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: CURRENT POSITION 1 Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:15 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::stPlaybackTimer Apr 11 16:59:15 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":23200,"duration":364,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"405 Kbps","isStreaming":false,"title":"1887380&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887380&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:15 pecanpiplus volumio[827]: verbose: CURRENT POSITION 1 Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus pause Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:15 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:15 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:15 pecanpiplus volumio[827]: info: CoreStateMachine::stPlaybackTimer Apr 11 16:59:15 pecanpiplus volumio[827]: info: ------------------------------ 53ms Apr 11 16:59:15 pecanpiplus volumio[827]: info: ------------------------------ 54ms Apr 11 16:59:15 pecanpiplus volumio[827]: info: ------------------------------ 54ms Apr 11 16:59:15 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:15 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:15 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:18 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:18 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: tidal , goto Apr 11 16:59:19 pecanpiplus volumio[827]: info: explodeTIDALUri took 141 milliseconds Apr 11 16:59:19 pecanpiplus volumio[827]: info: browseTIDALUri took 417 milliseconds Apr 11 16:59:19 pecanpiplus volumio[827]: info: No valid Plugin REST Endpoint: getSimilarAlbums Apr 11 16:59:19 pecanpiplus volumio[827]: info: No valid Plugin REST Endpoint: getSimilarAlbums Apr 11 16:59:21 pecanpiplus volumio[827]: info: Preload queue cleared Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::ClearQueue Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::stop Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::updateTrackBlock Apr 11 16:59:21 pecanpiplus volumio[827]: info: CorePlayQueue::getTrackBlock Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::stPlaybackTimer Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:21 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:21 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:21 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::serviceStop Apr 11 16:59:21 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreCommandRouter::serviceStop Apr 11 16:59:21 pecanpiplus volumio[827]: info: [1775919561890] ControllerTidal::stop Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 16:59:21 pecanpiplus volumio[827]: info: ControllerMpd::stop Apr 11 16:59:21 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 16:59:21 pecanpiplus volumio[827]: info: CorePlayQueue::clearPlayQueue Apr 11 16:59:21 pecanpiplus volumio[827]: info: CorePlayQueue::saveQueue Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushQueue Apr 11 16:59:21 pecanpiplus volumio[827]: info: CoreStateMachine::addQueueItems Apr 11 16:59:21 pecanpiplus volumio[827]: info: CorePlayQueue::addQueueItems Apr 11 16:59:21 pecanpiplus volumio[827]: info: Preload queue cleared Apr 11 16:59:21 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887378 Apr 11 16:59:21 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887378 in service tidal Apr 11 16:59:21 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887379 Apr 11 16:59:21 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887379 in service tidal Apr 11 16:59:21 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887380 Apr 11 16:59:21 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887380 in service tidal Apr 11 16:59:21 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887381 Apr 11 16:59:21 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887381 in service tidal Apr 11 16:59:21 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887207 Apr 11 16:59:21 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887207 in service tidal Apr 11 16:59:21 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887208 Apr 11 16:59:21 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887208 in service tidal Apr 11 16:59:21 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887209 Apr 11 16:59:21 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887209 in service tidal Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand stop took 114 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:22 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:22 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand status took 9 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand status took 8 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand status took 5 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:22 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:22 pecanpiplus volumio[827]: 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":"1887380&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887380&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: CURRENT POSITION 1 Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: No code Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:22 pecanpiplus volumio[827]: 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":"1887380&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887380&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: CURRENT POSITION 1 Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: No code Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 1 Apr 11 16:59:22 pecanpiplus volumio[827]: 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":"1887380&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887380&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: CURRENT POSITION 1 Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: No code Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:22 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 106ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 104ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 103ms Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 388 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 440 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 489 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 513 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 530 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 553 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 568 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushQueue Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::saveQueue Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::updateTrackBlock Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::getTrackBlock Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPlay Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::play index 6 Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::addQueueItems Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::addQueueItems Apr 11 16:59:22 pecanpiplus volumio[827]: info: Preload queue cleared Apr 11 16:59:22 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887210 Apr 11 16:59:22 pecanpiplus volumio[827]: info: Exploding uri tidal://song/1887210 in service tidal Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::play index undefined Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::startPlaybackTimer Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:22 pecanpiplus volumio[827]: info: [1775919562514] ControllerTidal::clearAddPlayTrack Apr 11 16:59:22 pecanpiplus volumio[827]: info: Getting stream with soundQuality HI_RES Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand stop took 8 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand clear took 2 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES" Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:22 pecanpiplus volumio[827]: {"status":"pause","position":1,"title":"4 Impromptus, D. 899, Op. 90: No. 3 in G-Flat Major","artist":"Murray Perahia","album":"Schubert: Impromptus, D. 899 (Op. 90) & D. 935 (Op. 142)","albumart":"https://resources.tidal.com/images/f927db39/71a4/4996/a753/e439d83ecdb3/640x640.jpg","uri":"tidal://song/1887380","trackType":"tidal","seek":0,"duration":364,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"bitrate":"439 Kbps","random":false,"repeat":false,"repeatSingle":false,"consume":true,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 11 16:59:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:22 pecanpiplus volumio[827]: error: updateQueue error: null Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 7ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES" took 7 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 6ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 4ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 16:59:22 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand play Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Apr 11 16:59:22 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:22 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:22 pecanpiplus volumio[827]: STREAMING PROXY: Handling url /?data=tidal://song/1887209&soundQuality=HI_RES Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 8ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: sendMpdCommand play took 6 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 5ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: ------------------------------ 4ms Apr 11 16:59:22 pecanpiplus volumio[827]: info: Executing endpoint getStreamUrltidal Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Apr 11 16:59:22 pecanpiplus volumio[827]: info: explodeTIDALUri took 263 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushQueue Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::saveQueue Apr 11 16:59:22 pecanpiplus volumio[827]: info: CoreStateMachine::updateTrackBlock Apr 11 16:59:22 pecanpiplus volumio[827]: info: CorePlayQueue::getTrackBlock Apr 11 16:59:22 pecanpiplus volumio[827]: info: getStreamUrl took 422 milliseconds Apr 11 16:59:22 pecanpiplus volumio[827]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidmNmMyNWQzNTFiMDliMmU0ZWRlMTdiYWE1MGI1NDYxZV82MS5tcDQ/0.flac?token=1775923162~ZGVkMjQ3ZWU2NjBkYzk5NDE1NjE3ZTY3NzlkMWFiNjUwODY3ZGI1NQ== Apr 11 16:59:22 pecanpiplus volumio[827]: STREAMING PROXY: Requesting upstream with range: none Apr 11 16:59:23 pecanpiplus volumio[827]: STREAMING PROXY: Upstream status code: 200 Apr 11 16:59:23 pecanpiplus volumio[827]: info: Apr 11 16:59:23 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:23 pecanpiplus volumio[827]: info: Apr 11 16:59:23 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:23 pecanpiplus volumio[827]: info: Apr 11 16:59:23 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:23 pecanpiplus volumio[827]: info: Apr 11 16:59:23 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand status took 14 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand status took 11 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:23 pecanpiplus volumio[827]: info: Apr 11 16:59:23 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:23 pecanpiplus volumio[827]: info: Apr 11 16:59:23 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand status took 39 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand status took 36 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 26 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 25 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand status took 20 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand status took 14 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"455 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: CURRENT POSITION 6 Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus stop Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"453 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: CURRENT POSITION 6 Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:23 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: ------------------------------ 136ms Apr 11 16:59:23 pecanpiplus volumio[827]: info: ------------------------------ 136ms Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 78 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 75 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 74 milliseconds Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"435 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: CURRENT POSITION 6 Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:23 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"516 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: CURRENT POSITION 6 Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:23 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"496 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: CURRENT POSITION 6 Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:23 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"496 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:23 pecanpiplus volumio[827]: verbose: CURRENT POSITION 6 Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:23 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:23 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:23 pecanpiplus volumio[827]: info: ------------------------------ 340ms Apr 11 16:59:23 pecanpiplus volumio[827]: info: ------------------------------ 338ms Apr 11 16:59:23 pecanpiplus volumio[827]: info: ------------------------------ 320ms Apr 11 16:59:23 pecanpiplus volumio[827]: info: ------------------------------ 314ms Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:24 pecanpiplus volumio[827]: info: Preload queue cleared Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::ClearQueue Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::stop Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::stPlaybackTimer Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::updateTrackBlock Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrackBlock Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::serviceStop Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 6 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::serviceStop Apr 11 16:59:24 pecanpiplus volumio[827]: info: [1775919564036] ControllerTidal::stop Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::stop Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::clearPlayQueue Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::saveQueue Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushQueue Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::addQueueItems Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::addQueueItems Apr 11 16:59:24 pecanpiplus volumio[827]: info: Preload queue cleared Apr 11 16:59:24 pecanpiplus volumio[827]: info: Adding Item to queue: tidal://song/1887209 Apr 11 16:59:24 pecanpiplus volumio[827]: info: Using cached record of: tidal://song/1887209 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushQueue Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Client closed connection Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::saveQueue Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Upstream closed. Received 5242880 bytes Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Incomplete transfer. Expected 38299278, got 5242880 Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Retrying with range: bytes=5242880- (attempt 1) Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::updateTrackBlock Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrackBlock Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPlay Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::play index 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::stop Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::play index undefined Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::startPlaybackTimer Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: [1775919564067] ControllerTidal::clearAddPlayTrack Apr 11 16:59:24 pecanpiplus volumio[827]: info: Getting stream with soundQuality HI_RES Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 16:59:24 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand stop took 55 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand stop took 24 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:24 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 15 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand clear took 14 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 13 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 11 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES" Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 58ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 57ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:24 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:24 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:24 pecanpiplus volumio[827]: error: updateQueue error: null Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:24 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 58ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 53 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES" took 52 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 9ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 7ms Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand play Apr 11 16:59:24 pecanpiplus volumio[827]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 79ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:24 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Handling url /?data=tidal://song/1887209&soundQuality=HI_RES Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces system playlist update Apr 11 16:59:24 pecanpiplus volumio[827]: info: Ignoring MPD Status Update Apr 11 16:59:24 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:24 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 23ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand play took 18 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 16ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 14ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: Executing endpoint getStreamUrltidal Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Apr 11 16:59:24 pecanpiplus volumio[827]: info: getStreamUrl took 237 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidmNmMyNWQzNTFiMDliMmU0ZWRlMTdiYWE1MGI1NDYxZV82MS5tcDQ/0.flac?token=1775923162~ZGVkMjQ3ZWU2NjBkYzk5NDE1NjE3ZTY3NzlkMWFiNjUwODY3ZGI1NQ== Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Requesting upstream with range: none Apr 11 16:59:24 pecanpiplus volumio[827]: STREAMING PROXY: Upstream status code: 200 Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 11 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 9 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 7 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: Apr 11 16:59:24 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 25 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 21 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 18 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 17 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 12 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand status took 16 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: CURRENT POSITION 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus stop Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: CURRENT POSITION 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:24 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"286 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: CURRENT POSITION 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:24 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 180ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 269ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: ------------------------------ 269ms Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 269 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 262 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 260 milliseconds Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1075,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"298 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: CURRENT POSITION 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:24 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"516 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: CURRENT POSITION 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:24 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":652,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"496 Kbps","isStreaming":false,"title":"1887209&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/1887209&soundQuality=HI_RES","trackType":"tidal"} Apr 11 16:59:24 pecanpiplus volumio[827]: verbose: CURRENT POSITION 0 Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState stateService play Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::syncState currentStatus play Apr 11 16:59:24 pecanpiplus volumio[827]: info: Received an update from plugin. extracting info from payload Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:24 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:25 pecanpiplus volumio[827]: info: ------------------------------ 547ms Apr 11 16:59:25 pecanpiplus volumio[827]: info: ------------------------------ 534ms Apr 11 16:59:25 pecanpiplus volumio[827]: info: ------------------------------ 530ms Apr 11 16:59:25 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:25 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:25 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:25 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:25 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:25 pecanpiplus volumio[827]: STREAMING PROXY: Resuming with range: bytes=5242880- Apr 11 16:59:25 pecanpiplus volumio[827]: STREAMING PROXY: Resume upstream status code: 206 Apr 11 16:59:30 pecanpiplus volumio[827]: STREAMING PROXY: Upstream closed. Received 38299278 bytes Apr 11 16:59:30 pecanpiplus volumio[827]: STREAMING PROXY: Client closed connection Apr 11 16:59:30 pecanpiplus volumio[827]: STREAMING PROXY: Resume ended. Received 33056398 bytes Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioGetState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioGetState Apr 11 16:59:46 pecanpiplus volumio[827]: info: Currently active: tidal Apr 11 16:59:46 pecanpiplus volumio[827]: info: Stopping currently active service Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioStop Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::stop Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::stPlaybackTimer Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::updateTrackBlock Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrackBlock Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::serviceStop Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::serviceStop Apr 11 16:59:46 pecanpiplus volumio[827]: info: [1775919586254] ControllerTidal::stop Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 16:59:46 pecanpiplus volumio[827]: info: ControllerMpd::stop Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 16:59:46 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: sendMpdCommand stop took 26 milliseconds Apr 11 16:59:46 pecanpiplus volumio[827]: info: TidalConnect Active Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioGetState Apr 11 16:59:46 pecanpiplus volumio[827]: info: Currently active: mpd Apr 11 16:59:46 pecanpiplus volumio[827]: info: Setting Volatile state to tidalconnect Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 16:59:46 pecanpiplus volumio[827]: info: Apr 11 16:59:46 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:46 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:46 pecanpiplus volumio[827]: info: Apr 11 16:59:46 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:46 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:46 pecanpiplus volumio[827]: info: Apr 11 16:59:46 pecanpiplus volumio[827]: ---------------------------- MPD announces state update: player Apr 11 16:59:46 pecanpiplus volumio[827]: info: ControllerMpd::getState Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand status Apr 11 16:59:46 pecanpiplus volumio[827]: info: sendMpdCommand status took 10 milliseconds Apr 11 16:59:46 pecanpiplus volumio[827]: info: sendMpdCommand status took 8 milliseconds Apr 11 16:59:46 pecanpiplus volumio[827]: info: sendMpdCommand status took 8 milliseconds Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::parseState Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 16:59:46 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 11 16:59:46 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 11 16:59:46 pecanpiplus volumio[827]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:46 pecanpiplus volumio[827]: verbose: ControllerMpd::parseTrackInfo Apr 11 16:59:46 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Apr 11 16:59:46 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Apr 11 16:59:46 pecanpiplus volumio[827]: info: ControllerMpd::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Apr 11 16:59:46 pecanpiplus volumio[827]: info: ------------------------------ 52ms Apr 11 16:59:46 pecanpiplus volumio[827]: info: ------------------------------ 51ms Apr 11 16:59:46 pecanpiplus volumio[827]: info: ------------------------------ 51ms Apr 11 16:59:46 pecanpiplus vtcs[7838]: [2026-04-11 16:59:46.911] [tisoc] [warning] [PlaybackControllerImpl.cpp:498] Illegal state:1 Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:46 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:46 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:46 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 16:59:47 pecanpiplus volumio[827]: info: Pushing metadata Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:47 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: info: CorePlayQueue::getTrack 0 Apr 11 16:59:47 pecanpiplus volumio[827]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:47 pecanpiplus vtcs[7838]: [2026-04-11 16:59:47.653] [tisoc] [warning] [PlaybackControllerImpl.cpp:213] Ignore play request because playback state is not STARTED. state_=2, playstate_=1, player_state_=0 Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:47 pecanpiplus volumio[827]: info: Pushing metadata Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:47 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:47 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:47 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:47 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 16:59:47 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:47 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:48 pecanpiplus vtcs[7838]: [close:85] Entering Apr 11 16:59:48 pecanpiplus vtcs[7838]: [close:100] Exiting Apr 11 16:59:48 pecanpiplus vtcs[7838]: [open:50] Opening with sample rate: 44100, type: 0 Apr 11 16:59:48 pecanpiplus vtcs[7838]: [start:106] Entering Apr 11 16:59:48 pecanpiplus vtcs[7838]: [start:113] Reopening PCM device... Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:48 pecanpiplus vtcs[7838]: [start:115] PCM opened successfully. Apr 11 16:59:48 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:48 pecanpiplus vtcs[7838]: [start:120] Exiting Apr 11 16:59:48 pecanpiplus vtcs[7838]: [feedThread:223] Entering Apr 11 16:59:48 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:48 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:48 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 16:59:48 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 16:59:48 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 16:59:48 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 16:59:48 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 16:59:52 pecanpiplus volumio[827]: {"status":"play","title":"Purcell: The Fairy Queen, Z.629 - Ed. Britten, Holst, Pears / Act 3: \"O Let Me Weep, For Ever Weep\"","artist":"Jennifer Vyvyan, English Chamber Orchestra, Benjamin Britten","album":"Purcell: The Fairy Queen; Dido & Aeneas","albumart":"https://resources.tidal.com/images/b30eb478/9cfa/4981/81bc/e0175578ba54/1280x1280.jpg","uri":"","trackType":"tidal","codec":"flac","seek":599,"duration":470,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"tidalconnect"} Apr 11 16:59:52 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:03 pecanpiplus vtcs[7838]: [close:85] Entering Apr 11 17:00:03 pecanpiplus vtcs[7838]: [feedThread:276] Exiting Apr 11 17:00:03 pecanpiplus vtcs[7838]: [close:100] Exiting Apr 11 17:00:03 pecanpiplus volumio[827]: info: Pushing metadata Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus vtcs[7838]: [2026-04-11 17:00:03.398] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=2, playstate_=1, player_state_=0 Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:03 pecanpiplus vtcs[7838]: [close:85] Entering Apr 11 17:00:03 pecanpiplus vtcs[7838]: [close:100] Exiting Apr 11 17:00:03 pecanpiplus volumio[827]: info: Pushing metadata Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:03 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 0 Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:03 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:04 pecanpiplus vtcs[7838]: [close:85] Entering Apr 11 17:00:04 pecanpiplus vtcs[7838]: [close:100] Exiting Apr 11 17:00:04 pecanpiplus vtcs[7838]: [open:50] Opening with sample rate: 44100, type: 0 Apr 11 17:00:04 pecanpiplus vtcs[7838]: [start:106] Entering Apr 11 17:00:04 pecanpiplus vtcs[7838]: [start:113] Reopening PCM device... Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:04 pecanpiplus vtcs[7838]: [start:115] PCM opened successfully. Apr 11 17:00:04 pecanpiplus vtcs[7838]: [start:120] Exiting Apr 11 17:00:04 pecanpiplus vtcs[7838]: [feedThread:223] Entering Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:04 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:04 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:04 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:04 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreCommandRouter::servicePushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreStateMachine::pushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:00:04 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioPushState Apr 11 17:00:04 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output update for this device Apr 11 17:00:04 pecanpiplus volumio[827]: info: MRS: Pushing multiroomSync output Apr 11 17:00:04 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:10 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:10 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:11 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:11 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:16 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:16 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:16 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:16 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:18 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:18 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:18 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:18 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:18 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioGetQueue Apr 11 17:00:18 pecanpiplus volumio[827]: info: CoreStateMachine::getQueue Apr 11 17:00:18 pecanpiplus volumio[827]: info: CorePlayQueue::getQueue Apr 11 17:00:22 pecanpiplus volumio[827]: {"status":"play","title":"Purcell: The Fairy Queen, Z.629 - Ed. Britten, Holst, Pears / Act 3: \"Now the Maids and the Men Are Making Of Hay\"","artist":"Alfreda Hodgson, Peter Pears, English Chamber Orchestra, Benjamin Britten","album":"Purcell: The Fairy Queen; Dido & Aeneas","albumart":"https://resources.tidal.com/images/b30eb478/9cfa/4981/81bc/e0175578ba54/1280x1280.jpg","uri":"","trackType":"tidal","codec":"flac","seek":524,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"tidalconnect"} Apr 11 17:00:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:22 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:22 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:23 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:23 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:26 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:26 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:26 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:26 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:31 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:31 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:31 pecanpiplus volumio[827]: info: Touch event received, exiting sleep mode Apr 11 17:00:31 pecanpiplus volumio[827]: ACTIVITY STATUS CHANGED TO: 1 Apr 11 17:00:31 pecanpiplus volumio[827]: info: CoreCommandRouter::volumioRemoveQueueItem Apr 11 17:00:31 pecanpiplus volumio[827]: info: CoreStateMachine::removeQueueItem Apr 11 17:00:31 pecanpiplus volumio[827]: info: CoreStateMachine::stop Apr 11 17:00:31 pecanpiplus volumio[827]: info: CoreStateMachine::serviceStop Apr 11 17:00:31 pecanpiplus volumio[827]: info: CoreCommandRouter::serviceStop Apr 11 17:00:31 pecanpiplus vtcs[7838]: [close:85] Entering Apr 11 17:00:31 pecanpiplus vtcs[7838]: [feedThread:276] Exiting Apr 11 17:00:31 pecanpiplus vtcs[7838]: [close:100] Exiting Apr 11 17:00:31 pecanpiplus volumio[827]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 17:00:31 pecanpiplus volumio[827]: TypeError: Cannot read property 'then' of undefined Apr 11 17:00:31 pecanpiplus volumio[827]: at CoreStateMachine.removeQueueItem (/volumio/app/statemachine.js:1372:7) Apr 11 17:00:31 pecanpiplus volumio[827]: at CoreCommandRouter.volumioRemoveQueueItem (/volumio/app/index.js:121:28) Apr 11 17:00:31 pecanpiplus volumio[827]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:173:33) Apr 11 17:00:31 pecanpiplus volumio[827]: at Socket.emit (events.js:315:20) Apr 11 17:00:31 pecanpiplus volumio[827]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Apr 11 17:00:31 pecanpiplus volumio[827]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 11 17:00:31 pecanpiplus volumio[827]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 17:00:31 pecanpiplus vtcs[7838]: [2026-04-11 17:00:31] [info] asio async_shutdown error: asio.misc:2 (End of file) Apr 11 17:00:31 pecanpiplus vtcs[7838]: [2026-04-11 17:00:31.736] [tisoc] [warning] [PlaybackControllerImpl.cpp:498] Illegal state:0 Apr 11 17:00:33 pecanpiplus sudo[6747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-11 16:59 Apr 11 17:00:33 pecanpiplus sudo[6747]: 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="3dada8b1e619a5feb94867e0865ace17474d7bce" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="30045b259d1a704a832ca7c1460c1fdfa4b723f9" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="orchard" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Mar 2026 11:40:31 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi-kiosk" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_VENDOR_MODEL="Orchard Audio PecanPi+ Streamer Premium" VOLUMIO_VENDOR="Orchard Audio" VOLUMIO_MODEL="PecanPi+ Streamer Premium" VOLUMIO_HASH="3139c1501464197c1c80bce80492e4a3"