-- Logs begin at Wed 2025-05-21 21:24:55 CEST, end at Wed 2025-05-21 21:36:23 CEST. -- May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:00 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:00 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:00 volumio5bern volumio[1388]: info: [1747856100572] ControllerTidal::resume May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:00 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:00 volumio5bern volumio[1388]: info: May 21 21:35:00 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:00 volumio5bern volumio[1388]: info: sendMpdCommand play took 1 milliseconds May 21 21:35:00 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:00 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:00 volumio5bern volumio[1388]: info: May 21 21:35:00 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:00 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:00 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:00 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:00 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:00 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:00 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":38781,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"750 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:00 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:00 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:35:00 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 12 milliseconds May 21 21:35:00 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:00 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:00 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:00 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":38849,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"685 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:00 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:00 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:00 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:00 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:00 volumio5bern volumio[1388]: info: ------------------------------ 21ms May 21 21:35:00 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:00 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:00 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:00 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:07 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:07 volumio5bern volumio[1388]: info: [1747856107266] ControllerTidal::pause May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:07 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:07 volumio5bern volumio[1388]: info: May 21 21:35:07 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:07 volumio5bern volumio[1388]: info: sendMpdCommand pause took 2 milliseconds May 21 21:35:07 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:07 volumio5bern volumio[1388]: info: May 21 21:35:07 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:07 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:07 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:07 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:07 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:07 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:07 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:07 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":46331,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"907 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:07 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:07 volumio5bern volumio[1388]: info: ------------------------------ 9ms May 21 21:35:07 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 7 milliseconds May 21 21:35:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:07 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:07 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:07 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":46331,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"907 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:07 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:07 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:07 volumio5bern volumio[1388]: info: ------------------------------ 16ms May 21 21:35:07 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:07 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:07 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:07 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:07 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:08 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:08 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:08 volumio5bern volumio[1388]: info: [1747856108356] ControllerTidal::resume May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:08 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:08 volumio5bern volumio[1388]: info: May 21 21:35:08 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:08 volumio5bern volumio[1388]: info: sendMpdCommand play took 2 milliseconds May 21 21:35:08 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:08 volumio5bern volumio[1388]: info: May 21 21:35:08 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:08 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:08 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:08 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:08 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:08 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:08 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:08 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:08 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":46423,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"844 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:08 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:08 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:08 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:08 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":46468,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"815 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:08 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:08 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:08 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:08 volumio5bern volumio[1388]: info: ------------------------------ 15ms May 21 21:35:08 volumio5bern volumio[1388]: info: ------------------------------ 15ms May 21 21:35:08 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:08 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:08 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:08 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:18 volumio5bern volumio[1388]: info: [1747856118426] ControllerTidal::pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:18 volumio5bern volumio[1388]: info: May 21 21:35:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand pause took 1 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:18 volumio5bern volumio[1388]: info: May 21 21:35:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":57336,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"935 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":57336,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"935 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:18 volumio5bern volumio[1388]: info: ------------------------------ 11ms May 21 21:35:18 volumio5bern volumio[1388]: info: ------------------------------ 10ms May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: info: [1747856118446] ControllerTidal::resume May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:18 volumio5bern volumio[1388]: info: May 21 21:35:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand play took 7 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:18 volumio5bern volumio[1388]: info: May 21 21:35:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand status took 3 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":58137,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"756 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":58343,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"844 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:18 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:18 volumio5bern volumio[1388]: info: ------------------------------ 17ms May 21 21:35:18 volumio5bern volumio[1388]: info: ------------------------------ 16ms May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:18 volumio5bern volumio[1388]: info: [1747856118713] ControllerTidal::pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand pause took 2 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: info: May 21 21:35:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:18 volumio5bern volumio[1388]: info: May 21 21:35:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":58595,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"789 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:18 volumio5bern volumio[1388]: info: ------------------------------ 6ms May 21 21:35:18 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 5 milliseconds May 21 21:35:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":58595,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"789 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:18 volumio5bern volumio[1388]: info: ------------------------------ 10ms May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:18 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:19 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:19 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:19 volumio5bern volumio[1388]: info: [1747856119913] ControllerTidal::resume May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:19 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:19 volumio5bern volumio[1388]: info: May 21 21:35:19 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:19 volumio5bern volumio[1388]: info: sendMpdCommand play took 2 milliseconds May 21 21:35:19 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:19 volumio5bern volumio[1388]: info: May 21 21:35:19 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:19 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:19 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:19 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:19 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:19 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:19 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:19 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":58686,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"796 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:19 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:19 volumio5bern volumio[1388]: info: ------------------------------ 11ms May 21 21:35:19 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 11 milliseconds May 21 21:35:19 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:19 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:19 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:19 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":58709,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"796 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:19 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:19 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:19 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:19 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:19 volumio5bern volumio[1388]: info: ------------------------------ 20ms May 21 21:35:19 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:19 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:19 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:19 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:22 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:22 volumio5bern volumio[1388]: info: [1747856122613] ControllerTidal::pause May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:22 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:22 volumio5bern volumio[1388]: info: May 21 21:35:22 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:22 volumio5bern volumio[1388]: info: sendMpdCommand pause took 2 milliseconds May 21 21:35:22 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:22 volumio5bern volumio[1388]: info: May 21 21:35:22 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:22 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:22 volumio5bern volumio[1388]: info: sendMpdCommand status took 3 milliseconds May 21 21:35:22 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:22 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:22 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:22 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:22 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:22 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:22 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":62233,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"741 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:22 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:22 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:22 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:22 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":62233,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"741 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:22 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:22 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:22 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:22 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:35:22 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:35:22 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:22 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:22 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:22 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:22 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:26 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:27 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 21 21:35:27 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:28 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:28 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:28 volumio5bern volumio[1388]: info: [1747856128369] ControllerTidal::resume May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:28 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:28 volumio5bern volumio[1388]: info: May 21 21:35:28 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:28 volumio5bern volumio[1388]: info: sendMpdCommand play took 2 milliseconds May 21 21:35:28 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:28 volumio5bern volumio[1388]: info: May 21 21:35:28 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:28 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:28 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:28 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:28 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:28 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:28 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:28 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":62324,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"821 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:28 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:28 volumio5bern volumio[1388]: info: ------------------------------ 8ms May 21 21:35:28 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 6 milliseconds May 21 21:35:28 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:28 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:28 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:28 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":62370,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"780 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:28 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:28 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:28 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:28 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:28 volumio5bern volumio[1388]: info: ------------------------------ 15ms May 21 21:35:28 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:28 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:28 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:28 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:30 volumio5bern volumio[1388]: info: CoreCommandRouter::getUIConfigOnPlugin May 21 21:35:30 volumio5bern volumio[1388]: info: [ASDebug] Setting UI defaults May 21 21:35:30 volumio5bern volumio[1388]: info: [ASDebug] Port: 19 May 21 21:35:30 volumio5bern volumio[1388]: info: [ASDebug] Inverted: true May 21 21:35:30 volumio5bern volumio[1388]: info: [ASDebug] Latched: false May 21 21:35:30 volumio5bern volumio[1388]: info: [ASDebug] On pulse width: 500 May 21 21:35:30 volumio5bern volumio[1388]: info: [ASDebug] Off pulse width: 500 May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:32 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:32 volumio5bern volumio[1388]: info: [1747856132942] ControllerTidal::pause May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:32 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:32 volumio5bern volumio[1388]: info: May 21 21:35:32 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:32 volumio5bern volumio[1388]: info: sendMpdCommand pause took 1 milliseconds May 21 21:35:32 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:32 volumio5bern volumio[1388]: info: May 21 21:35:32 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:32 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:32 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:32 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:32 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:32 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:32 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:32 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":67747,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"869 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:32 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:32 volumio5bern volumio[1388]: info: ------------------------------ 8ms May 21 21:35:32 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 6 milliseconds May 21 21:35:32 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:32 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:32 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:32 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":67747,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"869 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:32 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:32 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:32 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:32 volumio5bern volumio[1388]: info: ------------------------------ 12ms May 21 21:35:32 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:32 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:32 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:32 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:32 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:33 volumio5bern volumio[1388]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] May 21 21:35:33 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions May 21 21:35:33 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Port: 19 May 21 21:35:33 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Inverted: false May 21 21:35:33 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Delay: 10 May 21 21:35:33 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Latched: false May 21 21:35:33 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: On Pulse width: 500 May 21 21:35:33 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Off Pulse width: 500 May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:35 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:35 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:35 volumio5bern volumio[1388]: info: [1747856135348] ControllerTidal::resume May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:35 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:35 volumio5bern volumio[1388]: info: May 21 21:35:35 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:35 volumio5bern volumio[1388]: info: sendMpdCommand play took 9 milliseconds May 21 21:35:35 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:35 volumio5bern volumio[1388]: info: May 21 21:35:35 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:35 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:35 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:35 volumio5bern volumio[1388]: info: sendMpdCommand status took 2 milliseconds May 21 21:35:35 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 2 milliseconds May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:35 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:35 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:35 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68547,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"864 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:35 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:35 volumio5bern volumio[1388]: info: ------------------------------ 11ms May 21 21:35:35 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 7 milliseconds May 21 21:35:35 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:35 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:35 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:35 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68730,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"800 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:35 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:35 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:35 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:35 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:35 volumio5bern volumio[1388]: info: ------------------------------ 19ms May 21 21:35:35 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:35 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:35 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:35 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:37 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:37 volumio5bern volumio[1388]: info: [1747856137282] ControllerTidal::pause May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:37 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:37 volumio5bern volumio[1388]: info: May 21 21:35:37 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:37 volumio5bern volumio[1388]: info: sendMpdCommand pause took 2 milliseconds May 21 21:35:37 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:37 volumio5bern volumio[1388]: info: May 21 21:35:37 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:37 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:37 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:37 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:37 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:37 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:37 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:37 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":70630,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"730 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:37 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:37 volumio5bern volumio[1388]: info: ------------------------------ 6ms May 21 21:35:37 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 5 milliseconds May 21 21:35:37 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:37 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:37 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:37 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":70630,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"730 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:37 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:37 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:37 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:37 volumio5bern volumio[1388]: info: ------------------------------ 10ms May 21 21:35:37 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:37 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:37 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:37 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:37 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:38 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:38 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:38 volumio5bern volumio[1388]: info: [1747856138380] ControllerTidal::resume May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:38 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:38 volumio5bern volumio[1388]: info: May 21 21:35:38 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:38 volumio5bern volumio[1388]: info: sendMpdCommand play took 7 milliseconds May 21 21:35:38 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:38 volumio5bern volumio[1388]: info: May 21 21:35:38 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:38 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:38 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:38 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:38 volumio5bern volumio[1388]: info: [1747856138388] ControllerTidal::resume May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:38 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:38 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:38 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:38 volumio5bern volumio[1388]: info: sendMpdCommand play took 1 milliseconds May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:38 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 3 milliseconds May 21 21:35:38 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 3 milliseconds May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:38 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:38 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:38 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:38 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":71270,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"864 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:38 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:38 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:38 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:38 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":71293,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"857 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:38 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:38 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:38 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:38 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:38 volumio5bern volumio[1388]: info: ------------------------------ 17ms May 21 21:35:38 volumio5bern volumio[1388]: info: ------------------------------ 17ms May 21 21:35:38 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:38 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:38 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:38 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:39 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:39 volumio5bern volumio[1388]: info: [1747856139345] ControllerTidal::pause May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:39 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:39 volumio5bern volumio[1388]: info: May 21 21:35:39 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:39 volumio5bern volumio[1388]: info: sendMpdCommand pause took 1 milliseconds May 21 21:35:39 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:39 volumio5bern volumio[1388]: info: May 21 21:35:39 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:39 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:39 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:39 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:39 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:39 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:39 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:39 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:39 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:39 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":72506,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"827 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:39 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:39 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:39 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:39 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":72506,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"827 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:39 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:39 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:39 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:39 volumio5bern volumio[1388]: info: ------------------------------ 10ms May 21 21:35:39 volumio5bern volumio[1388]: info: ------------------------------ 10ms May 21 21:35:39 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:39 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:39 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:39 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:39 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: info: [1747856148382] ControllerTidal::resume May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:48 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: info: [1747856148390] ControllerTidal::resume May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:48 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:48 volumio5bern volumio[1388]: info: May 21 21:35:48 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:48 volumio5bern volumio[1388]: info: sendMpdCommand play took 13 milliseconds May 21 21:35:48 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:48 volumio5bern volumio[1388]: info: sendMpdCommand play took 5 milliseconds May 21 21:35:48 volumio5bern volumio[1388]: info: May 21 21:35:48 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:48 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: info: [1747856148396] ControllerTidal::resume May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:48 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:48 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:48 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:35:48 volumio5bern volumio[1388]: info: sendMpdCommand play took 0 milliseconds May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:48 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:48 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:48 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:48 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73512,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"814 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:48 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:48 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:48 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:48 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73512,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"814 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:48 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:48 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:48 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:48 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:35:48 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:35:48 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:48 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:48 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:48 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:55 volumio5bern volumio[1388]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Port: 19 May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Inverted: true May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Delay: 10 May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Latched: false May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: On Pulse width: 500 May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] Saving Settings: Off Pulse width: 500 May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:35:55 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:35:55 volumio5bern volumio[1388]: info: [1747856155818] ControllerTidal::pause May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:55 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:35:55 volumio5bern volumio[1388]: info: May 21 21:35:55 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:55 volumio5bern volumio[1388]: info: sendMpdCommand pause took 2 milliseconds May 21 21:35:55 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:55 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:55 volumio5bern volumio[1388]: info: May 21 21:35:55 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:55 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:55 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:55 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:55 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:55 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:55 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":80880,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"839 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:55 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:55 volumio5bern volumio[1388]: info: ------------------------------ 8ms May 21 21:35:55 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 7 milliseconds May 21 21:35:55 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:55 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:55 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:55 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":80880,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"839 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:55 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:55 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:55 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:35:55 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:35:55 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:58 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:58 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:58 volumio5bern volumio[1388]: info: [1747856158401] ControllerTidal::resume May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:58 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:35:58 volumio5bern volumio[1388]: info: May 21 21:35:58 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:58 volumio5bern volumio[1388]: info: sendMpdCommand play took 3 milliseconds May 21 21:35:58 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:58 volumio5bern volumio[1388]: info: May 21 21:35:58 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:35:58 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:35:58 volumio5bern volumio[1388]: info: sendMpdCommand status took 3 milliseconds May 21 21:35:58 volumio5bern volumio[1388]: info: sendMpdCommand status took 3 milliseconds May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:35:58 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:35:58 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:58 volumio5bern volumio[1388]: info: [1747856158408] ControllerTidal::resume May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:35:58 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:35:58 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:58 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:35:58 volumio5bern volumio[1388]: info: sendMpdCommand play took 0 milliseconds May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:58 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:35:58 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:58 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:58 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":81086,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"876 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:58 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:58 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:35:58 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:35:58 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":81131,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"853 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:35:58 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:35:58 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:58 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:35:58 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:35:58 volumio5bern volumio[1388]: info: ------------------------------ 16ms May 21 21:35:58 volumio5bern volumio[1388]: info: ------------------------------ 16ms May 21 21:35:58 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:35:58 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:35:58 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:35:58 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:36:00 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:36:05 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:36:05 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:05 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:36:05 volumio5bern volumio[1388]: info: [1747856165614] ControllerTidal::pause May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:36:05 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:36:05 volumio5bern volumio[1388]: info: May 21 21:36:05 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:05 volumio5bern volumio[1388]: info: sendMpdCommand pause took 2 milliseconds May 21 21:36:05 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:05 volumio5bern volumio[1388]: info: May 21 21:36:05 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:05 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:05 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:36:05 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:05 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:36:05 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:05 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:05 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:05 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:05 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:05 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":89002,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"754 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:05 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:05 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:05 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:05 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:05 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:05 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:05 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":89002,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"754 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:05 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:05 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:05 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:05 volumio5bern volumio[1388]: info: ------------------------------ 10ms May 21 21:36:05 volumio5bern volumio[1388]: info: ------------------------------ 10ms May 21 21:36:05 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:36:05 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:36:05 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:36:05 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:36:05 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:36:07 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:36:07 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:07 volumio5bern volumio[1388]: info: [1747856167162] ControllerTidal::resume May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:36:07 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:36:07 volumio5bern volumio[1388]: info: May 21 21:36:07 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:07 volumio5bern volumio[1388]: info: sendMpdCommand play took 2 milliseconds May 21 21:36:07 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:07 volumio5bern volumio[1388]: info: May 21 21:36:07 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:07 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:07 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:07 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:36:07 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 1 milliseconds May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:07 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:07 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:07 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":89094,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"829 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:07 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:07 volumio5bern volumio[1388]: info: ------------------------------ 6ms May 21 21:36:07 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 6 milliseconds May 21 21:36:07 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:07 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:07 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:07 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":89116,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"829 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:07 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:36:07 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:07 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:07 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:07 volumio5bern volumio[1388]: info: ------------------------------ 15ms May 21 21:36:07 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:36:07 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:36:07 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:36:07 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:36:08 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:36:08 volumio5bern volumio[1388]: info: [1747856168403] ControllerTidal::pause May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:36:08 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:36:08 volumio5bern volumio[1388]: info: May 21 21:36:08 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:08 volumio5bern volumio[1388]: info: sendMpdCommand pause took 1 milliseconds May 21 21:36:08 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:08 volumio5bern volumio[1388]: info: May 21 21:36:08 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:08 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:08 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:36:08 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:08 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:36:08 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:08 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:08 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:08 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:08 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":91130,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"771 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:08 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:08 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:08 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:08 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":91130,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"771 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:08 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:08 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:08 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:08 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:36:08 volumio5bern volumio[1388]: info: ------------------------------ 13ms May 21 21:36:08 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:36:08 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:36:08 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:36:08 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:36:08 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:36:10 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:36:10 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:10 volumio5bern volumio[1388]: info: [1747856170058] ControllerTidal::resume May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:36:10 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:36:10 volumio5bern volumio[1388]: info: May 21 21:36:10 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:10 volumio5bern volumio[1388]: info: sendMpdCommand play took 1 milliseconds May 21 21:36:10 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:10 volumio5bern volumio[1388]: info: May 21 21:36:10 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:10 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:10 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:10 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:36:10 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:10 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:10 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:10 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91221,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"812 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:10 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:10 volumio5bern volumio[1388]: info: ------------------------------ 7ms May 21 21:36:10 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 6 milliseconds May 21 21:36:10 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:10 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:10 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:10 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91244,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"965 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:10 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:36:10 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:10 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:10 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:10 volumio5bern volumio[1388]: info: ------------------------------ 16ms May 21 21:36:10 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:36:10 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:36:10 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:36:10 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: play May 21 21:36:15 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 21 21:36:15 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioGetState May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPause May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::pause May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::servicePause May 21 21:36:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePause May 21 21:36:18 volumio5bern volumio[1388]: info: [1747856178443] ControllerTidal::pause May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:36:18 volumio5bern volumio[1388]: info: ControllerMpd::pause May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand pause May 21 21:36:18 volumio5bern volumio[1388]: info: May 21 21:36:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:18 volumio5bern volumio[1388]: info: sendMpdCommand pause took 2 milliseconds May 21 21:36:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:18 volumio5bern volumio[1388]: info: May 21 21:36:18 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:18 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:18 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:18 volumio5bern volumio[1388]: info: sendMpdCommand status took 0 milliseconds May 21 21:36:18 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":100511,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"852 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:18 volumio5bern volumio[1388]: info: ------------------------------ 6ms May 21 21:36:18 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 5 milliseconds May 21 21:36:18 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:18 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:18 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:18 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":100511,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"852 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:18 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService pause May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:18 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:18 volumio5bern volumio[1388]: info: CoreStateMachine::stPlaybackTimer May 21 21:36:18 volumio5bern volumio[1388]: info: ------------------------------ 12ms May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] CurState: pause PrevState: play May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] InitTimeout - Amp off in: 10 ms May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: OFF May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] Port: 19 May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] Inverted: true May 21 21:36:18 volumio5bern volumio[1388]: info: [ASDebug] Delay: 10 May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPlay May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::play index undefined May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined May 21 21:36:23 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::startPlaybackTimer May 21 21:36:23 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:23 volumio5bern volumio[1388]: info: [1747856183216] ControllerTidal::resume May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::setConsumeUpdateService mpd May 21 21:36:23 volumio5bern volumio[1388]: info: ControllerMpd::resume May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand play May 21 21:36:23 volumio5bern volumio[1388]: info: May 21 21:36:23 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:23 volumio5bern volumio[1388]: info: sendMpdCommand play took 10 milliseconds May 21 21:36:23 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:23 volumio5bern volumio[1388]: info: May 21 21:36:23 volumio5bern volumio[1388]: ---------------------------- MPD announces state update: player May 21 21:36:23 volumio5bern volumio[1388]: info: ControllerMpd::getState May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand status May 21 21:36:23 volumio5bern volumio[1388]: info: sendMpdCommand status took 2 milliseconds May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:23 volumio5bern volumio[1388]: info: sendMpdCommand status took 1 milliseconds May 21 21:36:23 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 0 milliseconds May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::parseState May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:23 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:23 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:23 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":101449,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"829 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:23 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus pause May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:23 volumio5bern volumio[1388]: info: ------------------------------ 9ms May 21 21:36:23 volumio5bern volumio[1388]: info: sendMpdCommand playlistinfo took 7 milliseconds May 21 21:36:23 volumio5bern volumio[1388]: verbose: ControllerMpd::parseTrackInfo May 21 21:36:23 volumio5bern volumio[1388]: info: ControllerMpd::pushState May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::servicePushState May 21 21:36:23 volumio5bern volumio[1388]: info: CorePlayQueue::getTrack 2 May 21 21:36:23 volumio5bern volumio[1388]: verbose: STATE SERVICE {"status":"play","position":0,"seek":101517,"duration":265,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"872 Kbps","isStreaming":false,"title":"88192118&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/88192118&soundQuality=HI_RES","trackType":"tidal"} May 21 21:36:23 volumio5bern volumio[1388]: verbose: CURRENT POSITION 2 May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::syncState stateService play May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::syncState currentStatus play May 21 21:36:23 volumio5bern volumio[1388]: info: Received an update from plugin. extracting info from payload May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:23 volumio5bern volumio[1388]: info: CoreStateMachine::pushState May 21 21:36:23 volumio5bern volumio[1388]: info: CoreCommandRouter::volumioPushState May 21 21:36:23 volumio5bern volumio[1388]: info: ------------------------------ 17ms May 21 21:36:23 volumio5bern volumio[1388]: info: [ASDebug] CurState: play PrevState: pause May 21 21:36:23 volumio5bern volumio[1388]: info: [ASDebug] Togle GPIO: ON May 21 21:36:23 volumio5bern volumio[1388]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 21 21:36:23 volumio5bern volumio[1388]: Error: EBADF: bad file descriptor, write May 21 21:36:23 volumio5bern volumio[1388]: at Object.writeSync (fs.js:711:3) May 21 21:36:23 volumio5bern volumio[1388]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) May 21 21:36:23 volumio5bern volumio[1388]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:209:23) May 21 21:36:23 volumio5bern volumio[1388]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:86) May 21 21:36:23 volumio5bern volumio[1388]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 21 21:36:23 volumio5bern volumio[1388]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) May 21 21:36:23 volumio5bern volumio[1388]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) May 21 21:36:23 volumio5bern volumio[1388]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 21 21:36:23 volumio5bern volumio[1388]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 21 21:36:23 volumio5bern volumio[1388]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) May 21 21:36:23 volumio5bern volumio[1388]: at Decoder. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 21 21:36:23 volumio5bern volumio[1388]: at Decoder.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 21 21:36:23 volumio5bern volumio[1388]: at Decoder.add (/data/plugins/system_controller/ampswitch/node_modules/socket.io-parser/index.js:254:12) May 21 21:36:23 volumio5bern volumio[1388]: at Manager.ondata (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:339:16) May 21 21:36:23 volumio5bern volumio[1388]: at Socket. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 21 21:36:23 volumio5bern volumio[1388]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) { May 21 21:36:23 volumio5bern volumio[1388]: errno: -9, May 21 21:36:23 volumio5bern volumio[1388]: syscall: 'write', May 21 21:36:23 volumio5bern volumio[1388]: code: 'EBADF' May 21 21:36:23 volumio5bern volumio[1388]: } May 21 21:36:23 volumio5bern volumio[1388]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 21 21:36:23 volumio5bern sudo[4886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-21 21:35 May 21 21:36:23 volumio5bern sudo[4886]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"