-- Logs begin at Thu 2025-06-05 18:04:51 CEST, end at Thu 2025-06-05 18:25:18 CEST. -- Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::servicePause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePause Jun 05 18:24:01 volumio5bern volumio[1247]: info: [1749140641046] ControllerTidal::pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:24:01 volumio5bern volumio[1247]: info: ControllerMpd::pause Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: sendMpdCommand pause took 1 milliseconds Jun 05 18:24:01 volumio5bern volumio[1247]: info: Jun 05 18:24:01 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:01 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:01 volumio5bern volumio[1247]: info: Jun 05 18:24:01 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:01 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:01 volumio5bern volumio[1247]: info: Jun 05 18:24:01 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:01 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:01 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:01 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:01 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:01 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:24:01 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:24:01 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:01 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":109228,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"862 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:01 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":109228,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"862 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:01 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":109228,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"862 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:01 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:01 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:01 volumio5bern volumio[1247]: info: ------------------------------ 16ms Jun 05 18:24:01 volumio5bern volumio[1247]: info: ------------------------------ 16ms Jun 05 18:24:01 volumio5bern volumio[1247]: info: ------------------------------ 16ms Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:24:01 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: OFF Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPlay Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::play index undefined Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 18:24:05 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::startPlaybackTimer Jun 05 18:24:05 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:05 volumio5bern volumio[1247]: info: [1749140645050] ControllerTidal::resume Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:24:05 volumio5bern volumio[1247]: info: ControllerMpd::resume Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand play Jun 05 18:24:05 volumio5bern volumio[1247]: info: sendMpdCommand play took 2 milliseconds Jun 05 18:24:05 volumio5bern volumio[1247]: info: Jun 05 18:24:05 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:05 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:05 volumio5bern volumio[1247]: info: Jun 05 18:24:05 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:05 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:05 volumio5bern volumio[1247]: info: Jun 05 18:24:05 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:05 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:05 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:05 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:05 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:05 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:05 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:05 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":109319,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"888 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":109365,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"811 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:24:05 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: ------------------------------ 18ms Jun 05 18:24:05 volumio5bern volumio[1247]: info: ------------------------------ 18ms Jun 05 18:24:05 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 16 milliseconds Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:05 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":109411,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"811 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:05 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:24:05 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:05 volumio5bern volumio[1247]: info: ------------------------------ 25ms Jun 05 18:24:05 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: pause Jun 05 18:24:05 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:24:05 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:24:05 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:05 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:05 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:05 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: OFF Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::servicePause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePause Jun 05 18:24:07 volumio5bern volumio[1247]: info: [1749140647040] ControllerTidal::pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:24:07 volumio5bern volumio[1247]: info: ControllerMpd::pause Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: sendMpdCommand pause took 1 milliseconds Jun 05 18:24:07 volumio5bern volumio[1247]: info: Jun 05 18:24:07 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:07 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:07 volumio5bern volumio[1247]: info: Jun 05 18:24:07 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:07 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:07 volumio5bern volumio[1247]: info: Jun 05 18:24:07 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:07 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:07 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:07 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:07 volumio5bern volumio[1247]: info: sendMpdCommand status took 0 milliseconds Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:07 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:07 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:07 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:07 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":112111,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"852 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:07 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":112111,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"852 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:07 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":112111,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"852 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:07 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:07 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:07 volumio5bern volumio[1247]: info: ------------------------------ 14ms Jun 05 18:24:07 volumio5bern volumio[1247]: info: ------------------------------ 13ms Jun 05 18:24:07 volumio5bern volumio[1247]: info: ------------------------------ 13ms Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:24:07 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: OFF Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPlay Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::play index undefined Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 18:24:08 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::startPlaybackTimer Jun 05 18:24:08 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:08 volumio5bern volumio[1247]: info: [1749140648436] ControllerTidal::resume Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:24:08 volumio5bern volumio[1247]: info: ControllerMpd::resume Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand play Jun 05 18:24:08 volumio5bern volumio[1247]: info: sendMpdCommand play took 2 milliseconds Jun 05 18:24:08 volumio5bern volumio[1247]: info: Jun 05 18:24:08 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:08 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:08 volumio5bern volumio[1247]: info: Jun 05 18:24:08 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:08 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:08 volumio5bern volumio[1247]: info: Jun 05 18:24:08 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:08 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:08 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:08 volumio5bern volumio[1247]: info: sendMpdCommand status took 2 milliseconds Jun 05 18:24:08 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:08 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:08 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":112202,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"819 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":112225,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"830 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:24:08 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":112317,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"830 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:08 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:24:08 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:08 volumio5bern volumio[1247]: info: ------------------------------ 23ms Jun 05 18:24:08 volumio5bern volumio[1247]: info: ------------------------------ 23ms Jun 05 18:24:08 volumio5bern volumio[1247]: info: ------------------------------ 22ms Jun 05 18:24:08 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: pause Jun 05 18:24:08 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:24:08 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:24:08 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:08 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:08 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: OFF Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::servicePause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePause Jun 05 18:24:10 volumio5bern volumio[1247]: info: [1749140650184] ControllerTidal::pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:24:10 volumio5bern volumio[1247]: info: ControllerMpd::pause Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: sendMpdCommand pause took 1 milliseconds Jun 05 18:24:10 volumio5bern volumio[1247]: info: Jun 05 18:24:10 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:10 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:10 volumio5bern volumio[1247]: info: Jun 05 18:24:10 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:10 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:10 volumio5bern volumio[1247]: info: Jun 05 18:24:10 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:10 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:10 volumio5bern volumio[1247]: info: sendMpdCommand status took 2 milliseconds Jun 05 18:24:10 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:10 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:10 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:10 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:10 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:10 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":114742,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"755 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:10 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":114742,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"755 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:10 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":114742,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"755 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:10 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:10 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:10 volumio5bern volumio[1247]: info: ------------------------------ 15ms Jun 05 18:24:10 volumio5bern volumio[1247]: info: ------------------------------ 15ms Jun 05 18:24:10 volumio5bern volumio[1247]: info: ------------------------------ 14ms Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:24:10 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: OFF Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPlay Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::play index undefined Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 18:24:12 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::startPlaybackTimer Jun 05 18:24:12 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:12 volumio5bern volumio[1247]: info: [1749140652158] ControllerTidal::resume Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:24:12 volumio5bern volumio[1247]: info: ControllerMpd::resume Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand play Jun 05 18:24:12 volumio5bern volumio[1247]: info: sendMpdCommand play took 2 milliseconds Jun 05 18:24:12 volumio5bern volumio[1247]: info: Jun 05 18:24:12 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:12 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:12 volumio5bern volumio[1247]: info: Jun 05 18:24:12 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:12 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:12 volumio5bern volumio[1247]: info: Jun 05 18:24:12 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:12 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:12 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:12 volumio5bern volumio[1247]: info: sendMpdCommand status took 0 milliseconds Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:12 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:12 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114833,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"743 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114856,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"743 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:24:12 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114879,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"743 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:12 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:24:12 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:12 volumio5bern volumio[1247]: info: ------------------------------ 20ms Jun 05 18:24:12 volumio5bern volumio[1247]: info: ------------------------------ 20ms Jun 05 18:24:12 volumio5bern volumio[1247]: info: ------------------------------ 19ms Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: pause Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: play Jun 05 18:24:12 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: OFF Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::servicePause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePause Jun 05 18:24:13 volumio5bern volumio[1247]: info: [1749140653291] ControllerTidal::pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:24:13 volumio5bern volumio[1247]: info: ControllerMpd::pause Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: sendMpdCommand pause took 1 milliseconds Jun 05 18:24:13 volumio5bern volumio[1247]: info: Jun 05 18:24:13 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:13 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:13 volumio5bern volumio[1247]: info: Jun 05 18:24:13 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:13 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:13 volumio5bern volumio[1247]: info: Jun 05 18:24:13 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:24:13 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:24:13 volumio5bern volumio[1247]: info: sendMpdCommand status took 0 milliseconds Jun 05 18:24:13 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:13 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:24:13 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:24:13 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:24:13 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:24:13 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":116870,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"863 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:13 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":116870,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"863 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:13 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":116870,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"863 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:24:13 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:24:13 volumio5bern volumio[1247]: info: CoreStateMachine::stPlaybackTimer Jun 05 18:24:13 volumio5bern volumio[1247]: info: ------------------------------ 14ms Jun 05 18:24:13 volumio5bern volumio[1247]: info: ------------------------------ 14ms Jun 05 18:24:13 volumio5bern volumio[1247]: info: ------------------------------ 14ms Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] CurState: pause PrevState: play Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] InitTimeout - Amp off in: 20 ms Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:24:13 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: OFF Jun 05 18:24:18 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 05 18:24:18 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 05 18:24:20 volumio5bern volumio[1247]: info: [ASDebug] Port: 18 Jun 05 18:24:20 volumio5bern volumio[1247]: info: [ASDebug] Inverted: false Jun 05 18:24:20 volumio5bern volumio[1247]: info: [ASDebug] Delay: 20 Jun 05 18:24:25 volumio5bern volumio[1247]: info: Enabling plugin iractivityled Jun 05 18:24:25 volumio5bern volumio[1247]: info: Loading plugin "iractivityled"... Jun 05 18:24:25 volumio5bern volumio[1247]: info: [IrActivityLed] Initialized Jun 05 18:24:25 volumio5bern volumio[1247]: info: PLUGIN START: iractivityled Jun 05 18:24:25 volumio5bern volumio[1247]: info: [IrActivityLed] lirc socket connect: attempt 1 of 20 Jun 05 18:24:25 volumio5bern volumio[1247]: info: [IrActivityLed] lircd service status: active Jun 05 18:24:25 volumio5bern lircd-0.10.1[1542]: Notice: accepted new client on /var/run/lirc/lircd Jun 05 18:24:25 volumio5bern lircd[1542]: lircd-0.10.1[1542]: Notice: accepted new client on /var/run/lirc/lircd Jun 05 18:24:25 volumio5bern volumio[1247]: info: [IrActivityLed] Connected to lirc socket Jun 05 18:24:25 volumio5bern volumio[1247]: info: [IrActivityLed] initializing built-in LED Jun 05 18:24:25 volumio5bern sudo[5299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /sys/class/leds/led1/brightness /sys/class/leds/led1/trigger Jun 05 18:24:25 volumio5bern sudo[5299]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 18:24:25 volumio5bern sudo[5299]: pam_unix(sudo:session): session closed for user root Jun 05 18:24:25 volumio5bern volumio[1247]: info: [IrActivityLed] Error: Command failed: /usr/bin/sudo /bin/chmod a+rw /sys/class/leds/led1/brightness /sys/class/leds/led1/trigger Jun 05 18:24:25 volumio5bern volumio[1247]: /bin/chmod: cannot access '/sys/class/leds/led1/brightness': No such file or directory Jun 05 18:24:25 volumio5bern volumio[1247]: /bin/chmod: cannot access '/sys/class/leds/led1/trigger': No such file or directory Jun 05 18:24:26 volumio5bern volumio[1247]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 18:24:36 volumio5bern volumio[1247]: info: CALLMETHOD: system_hardware iractivityled saveSettings [object Object] Jun 05 18:24:36 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: iractivityled , saveSettings Jun 05 18:24:52 volumio5bern volumio[1247]: info: CALLMETHOD: system_hardware iractivityled saveSettings [object Object] Jun 05 18:24:52 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: iractivityled , saveSettings Jun 05 18:25:00 volumio5bern volumio[1247]: info: CALLMETHOD: system_hardware iractivityled saveSettings [object Object] Jun 05 18:25:00 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: iractivityled , saveSettings Jun 05 18:25:06 volumio5bern volumio[1247]: info: CALLMETHOD: system_hardware iractivityled saveSettings [object Object] Jun 05 18:25:06 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: iractivityled , saveSettings Jun 05 18:25:10 volumio5bern ntpd[967]: 91.235.212.22 local addr 172.22.16.141 -> Jun 05 18:25:14 volumio5bern volumio[1247]: info: CALLMETHOD: system_hardware iractivityled saveSettings [object Object] Jun 05 18:25:14 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: iractivityled , saveSettings Jun 05 18:25:17 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioGetState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPlay Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::play index undefined Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 18:25:18 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::startPlaybackTimer Jun 05 18:25:18 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:25:18 volumio5bern volumio[1247]: info: [1749140718620] ControllerTidal::resume Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 05 18:25:18 volumio5bern volumio[1247]: info: ControllerMpd::resume Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand play Jun 05 18:25:18 volumio5bern volumio[1247]: info: sendMpdCommand play took 7 milliseconds Jun 05 18:25:18 volumio5bern volumio[1247]: info: Jun 05 18:25:18 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:25:18 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:25:18 volumio5bern volumio[1247]: info: Jun 05 18:25:18 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:25:18 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:25:18 volumio5bern volumio[1247]: info: Jun 05 18:25:18 volumio5bern volumio[1247]: ---------------------------- MPD announces state update: player Jun 05 18:25:18 volumio5bern volumio[1247]: info: ControllerMpd::getState Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand status Jun 05 18:25:18 volumio5bern volumio[1247]: info: sendMpdCommand status took 1 milliseconds Jun 05 18:25:18 volumio5bern volumio[1247]: info: sendMpdCommand status took 0 milliseconds Jun 05 18:25:18 volumio5bern volumio[1247]: info: sendMpdCommand status took 0 milliseconds Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::parseState Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 18:25:18 volumio5bern volumio[1247]: error: Upnp client error: Error: This socket has been ended by the other party Jun 05 18:25:18 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:25:18 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:25:18 volumio5bern volumio[1247]: info: sendMpdCommand playlistinfo took 0 milliseconds Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: ControllerMpd::parseTrackInfo Jun 05 18:25:18 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":117876,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"850 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus pause Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":117876,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"859 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:25:18 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: ControllerMpd::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::servicePushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CorePlayQueue::getTrack 5 Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":117876,"duration":182,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"859 Kbps","isStreaming":false,"title":"3166097&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3166097&soundQuality=HI_RES","trackType":"tidal"} Jun 05 18:25:18 volumio5bern volumio[1247]: verbose: CURRENT POSITION 5 Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::syncState stateService play Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::syncState currentStatus play Jun 05 18:25:18 volumio5bern volumio[1247]: info: Received an update from plugin. extracting info from payload Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreStateMachine::pushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: CoreCommandRouter::volumioPushState Jun 05 18:25:18 volumio5bern volumio[1247]: info: ------------------------------ 19ms Jun 05 18:25:18 volumio5bern volumio[1247]: info: ------------------------------ 19ms Jun 05 18:25:18 volumio5bern volumio[1247]: info: ------------------------------ 19ms Jun 05 18:25:18 volumio5bern volumio[1247]: info: [ASDebug] CurState: play PrevState: pause Jun 05 18:25:18 volumio5bern volumio[1247]: info: [ASDebug] Pulsing GPIO for 10ms Jun 05 18:25:18 volumio5bern volumio[1247]: info: [ASDebug] Togle GPIO: ON Jun 05 18:25:18 volumio5bern volumio[1247]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 18:25:18 volumio5bern volumio[1247]: Error: ESPIPE: invalid seek, write Jun 05 18:25:18 volumio5bern volumio[1247]: at Object.writeSync (fs.js:711:3) Jun 05 18:25:18 volumio5bern volumio[1247]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Jun 05 18:25:18 volumio5bern volumio[1247]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:207:23) Jun 05 18:25:18 volumio5bern volumio[1247]: at AmpSwitchController.pulse (/data/plugins/system_controller/ampswitch/index.js:231:8) Jun 05 18:25:18 volumio5bern volumio[1247]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:38) Jun 05 18:25:18 volumio5bern volumio[1247]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 05 18:25:18 volumio5bern volumio[1247]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) Jun 05 18:25:18 volumio5bern volumio[1247]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) Jun 05 18:25:18 volumio5bern volumio[1247]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Jun 05 18:25:18 volumio5bern volumio[1247]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 05 18:25:18 volumio5bern volumio[1247]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) Jun 05 18:25:18 volumio5bern volumio[1247]: at Decoder. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Jun 05 18:25:18 volumio5bern volumio[1247]: at Decoder.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 05 18:25:18 volumio5bern volumio[1247]: at Decoder.add (/data/plugins/system_controller/ampswitch/node_modules/socket.io-parser/index.js:254:12) Jun 05 18:25:18 volumio5bern volumio[1247]: at Manager.ondata (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:339:16) Jun 05 18:25:18 volumio5bern volumio[1247]: at Socket. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) { Jun 05 18:25:18 volumio5bern volumio[1247]: errno: -29, Jun 05 18:25:18 volumio5bern volumio[1247]: syscall: 'write', Jun 05 18:25:18 volumio5bern volumio[1247]: code: 'ESPIPE' Jun 05 18:25:18 volumio5bern volumio[1247]: } Jun 05 18:25:18 volumio5bern volumio[1247]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 18:25:18 volumio5bern sudo[5432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-05 18:24 Jun 05 18:25:18 volumio5bern sudo[5432]: 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"