May 27 21:34:00 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:00 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:01 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:02 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:02 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:03 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:03 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:04 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:04 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:05 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:05 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:06 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:07 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:07 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:08 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:08 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:09 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:09 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:10 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:10 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] -> POST /api/internal/speaker/events (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] <- POST /api/internal/speaker/events 200 (437ms) (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:11 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:12 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:12 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 45 May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume45 May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:13 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio play at index 0 May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPlay May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::play index 0 May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stop May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::play index undefined May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::startPlaybackTimer May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: [1779910454778] ControllerTidal::clearAddPlayTrack May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: Getting stream with soundQuality HI_RES May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:14 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: getStreamUrl took 543 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand stop May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand stop took 1 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand clear May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces system playlist update May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: Ignoring MPD Status Update May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand clear took 2 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5MWI2M2MwNmVmZTUzZTAzYzE3OTQ2M2I0MmNiMzI1NS5tcDQ/0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==" May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: error: updateQueue error: null May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces system playlist update May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: Ignoring MPD Status Update May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 4ms May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5MWI2M2MwNmVmZTUzZTAzYzE3OTQ2M2I0MmNiMzI1NS5tcDQ/0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==" took 3 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand play May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 4ms May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand play took 3 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 20 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 2 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 2 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":426,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5MWI2M2MwNmVmZTUzZTAzYzE3OTQ2M2I0MmNiMzI1NS5tcDQ/0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","trackType":"tidal"} May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus stop May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 28ms May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 7 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":426,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5MWI2M2MwNmVmZTUzZTAzYzE3OTQ2M2I0MmNiMzI1NS5tcDQ/0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","trackType":"tidal"} May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus play May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: Received an update from plugin. extracting info from payload May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 75ms May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::servicePause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: [1779910455853] ControllerTidal::pause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand pause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio next May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioNext May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::next May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::next May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand next May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand pause took 10 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand next took 27 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 24 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService stop May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus pause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 70ms May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (92ms) (action=executeCommand, command=pause) May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 56 milliseconds May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 0 May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService stop May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus pause May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:15 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 89ms May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (60ms) (action=setVolume, volumePercent=0) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] -> POST /api/internal/speaker/events (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (12ms) (action=executeCommand, command=pause) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (59ms) (action=setVolume, volumePercent=0) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (15ms) (action=executeCommand, command=pause) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (54ms) (action=setVolume, volumePercent=0) May 27 21:34:16 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] <- POST /api/internal/speaker/events 200 (952ms) (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] -> PUT /api/internal/speaker/snapshot (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (11ms) (action=executeCommand, command=pause) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (56ms) (action=setVolume, volumePercent=0) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (13ms) (action=executeCommand, command=pause) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (48ms) (action=setVolume, volumePercent=0) May 27 21:34:17 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:17 ode-spk-grefsen-04 tailscaled[629]: ssh-session(sess-20260527T193351-c0cc97c2f2): Session complete May 27 21:34:17 ode-spk-grefsen-04 systemd[1]: session-c6.scope: Deactivated successfully. May 27 21:34:17 ode-spk-grefsen-04 systemd-logind[628]: Session c6 logged out. Waiting for processes to exit. May 27 21:34:17 ode-spk-grefsen-04 systemd-logind[628]: Removed session c6. May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (9ms) (action=executeCommand, command=pause) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (50ms) (action=setVolume, volumePercent=0) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (9ms) (action=executeCommand, command=pause) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (47ms) (action=setVolume, volumePercent=0) May 27 21:34:18 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (19ms) (action=executeCommand, command=pause) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (49ms) (action=setVolume, volumePercent=0) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (17ms) (action=executeCommand, command=pause) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (47ms) (action=setVolume, volumePercent=0) May 27 21:34:19 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (9ms) (action=executeCommand, command=pause) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (54ms) (action=setVolume, volumePercent=0) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Tick heartbeat #2974 (duration=109ms, skipped=82, errors=1, potSwitch=false, slideSwitch=true, volumeLocked=false, intentGate=none, potRaw=0). May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] <- PUT /api/internal/speaker/snapshot 200 (3488ms) (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (12ms) (action=executeCommand, command=pause) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (54ms) (action=setVolume, volumePercent=0) May 27 21:34:20 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (11ms) (action=executeCommand, command=pause) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (51ms) (action=setVolume, volumePercent=0) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (9ms) (action=executeCommand, command=pause) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (55ms) (action=setVolume, volumePercent=0) May 27 21:34:21 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (14ms) (action=executeCommand, command=pause) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (52ms) (action=setVolume, volumePercent=0) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (10ms) (action=executeCommand, command=pause) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (54ms) (action=setVolume, volumePercent=0) May 27 21:34:22 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (14ms) (action=executeCommand, command=pause) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (52ms) (action=setVolume, volumePercent=0) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (9ms) (action=executeCommand, command=pause) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (53ms) (action=setVolume, volumePercent=0) May 27 21:34:23 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (12ms) (action=executeCommand, command=pause) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (52ms) (action=setVolume, volumePercent=0) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (9ms) (action=executeCommand, command=pause) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: warn: [ode-hardware-controls] Volumio still reports PLAYING after PAUSE for speaker spk_grefsen_04. May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (55ms) (action=setVolume, volumePercent=0) May 27 21:34:24 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Play attempt #1 started (pot switch on). May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=play (action=executeCommand, command=play) May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio play May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPlay May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::play index undefined May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::startPlaybackTimer May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [1779910465366] ControllerTidal::resume May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::resume May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand play May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=play 200 (12ms) (action=executeCommand, command=play) May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 54% (POTENTIOMETER). May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=54 (action=setVolume, volumePercent=54) May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand play took 10 milliseconds May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 54 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume54 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=54 200 (65ms) (action=setVolume, volumePercent=54) May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 54% (POTENTIOMETER). May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=54 (action=setVolume, volumePercent=54) May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 54 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume54 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=54 200 (55ms) (action=setVolume, volumePercent=54) May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Play attempt completed after 1 attempt(s). May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 20 milliseconds May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 8 milliseconds May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 9 milliseconds May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":426,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5MWI2M2MwNmVmZTUzZTAzYzE3OTQ2M2I0MmNiMzI1NS5tcDQ/0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","trackType":"tidal"} May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 0 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus pause May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 50ms May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 21 milliseconds May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":426,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5MWI2M2MwNmVmZTUzZTAzYzE3OTQ2M2I0MmNiMzI1NS5tcDQ/0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","trackType":"tidal"} May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 0 May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus play May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: Received an update from plugin. extracting info from payload May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 62ms May 27 21:34:25 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] -> PUT /api/internal/speaker/snapshot (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 65% (POTENTIOMETER). May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=65 (action=setVolume, volumePercent=65) May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 65 May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume65 May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=65 200 (63ms) (action=setVolume, volumePercent=65) May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 79% (POTENTIOMETER). May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=79 (action=setVolume, volumePercent=79) May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 79 May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume79 May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:26 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=79 200 (61ms) (action=setVolume, volumePercent=79) May 27 21:34:27 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:27 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] -> GET /api/internal/speaker/settings (speakerId=spk_grefsen_04). May 27 21:34:28 ode-spk-grefsen-04 tailscaled[629]: control: NetInfo: NetInfo{varies=true ipv6=false ipv6os=false udp=true icmpv4=false derp=#28 portmap= link="" firewallmode="ipt-default"} May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: Stopping user@1000.service - User Manager for UID 1000... May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Activating special unit exit.target... May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Stopped target default.target - Main User Target. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Stopped target basic.target - Basic System. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Stopped target paths.target - Paths. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Stopped target sockets.target - Sockets. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Stopped target timers.target - Timers. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Closed dirmngr.socket - GnuPG network certificate management daemon. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Removed slice app.slice - User Application Slice. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Reached target shutdown.target - Shutdown. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Finished systemd-exit.service - Exit the Session. May 27 21:34:28 ode-spk-grefsen-04 systemd[4586]: Reached target exit.target - Exit the Session. May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: user@1000.service: Deactivated successfully. May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: Stopped user@1000.service - User Manager for UID 1000. May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: run-user-1000.mount: Deactivated successfully. May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: user-runtime-dir@1000.service: Deactivated successfully. May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. May 27 21:34:28 ode-spk-grefsen-04 systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000. May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] <- PUT /api/internal/speaker/snapshot 200 (3242ms) (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] <- GET /api/internal/speaker/settings 200 (2448ms, speakerId=spk_grefsen_04). May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 77% (POTENTIOMETER). May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=77 (action=setVolume, volumePercent=77) May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 77 May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume77 May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:29 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=77 200 (73ms) (action=setVolume, volumePercent=77) May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 59% (POTENTIOMETER). May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=59 (action=setVolume, volumePercent=59) May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 59 May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume59 May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=59 200 (59ms) (action=setVolume, volumePercent=59) May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 50% (POTENTIOMETER). May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=50 (action=setVolume, volumePercent=50) May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 50 May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume50 May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:30 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=50 200 (64ms) (action=setVolume, volumePercent=50) May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::servicePause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [1779910471400] ControllerTidal::pause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand pause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand pause took 8 milliseconds May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 3 milliseconds May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (20ms) (action=executeCommand, command=pause) May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 7 milliseconds May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5960,"duration":426,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"838 Kbps","isStreaming":false,"title":"0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5MWI2M2MwNmVmZTUzZTAzYzE3OTQ2M2I0MmNiMzI1NS5tcDQ/0.flac?token=1779914055~ZGFkNDI0Mjk2Mzk1YzgxZmIzMDBiOTZkYWM3YzM4OWRhODE1NTg4Zg==","trackType":"tidal"} May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 0 May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService pause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus pause May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 34ms May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (65ms) (action=setVolume, volumePercent=0) May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:31 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Quick off-on gesture requested SKIP_NEXT. May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=play&N=1 (action=playQueuePosition, command=play) May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio play at index 1 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPlay May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::play index 1 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stop May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::updateTrackBlock May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrackBlock May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::serviceStop May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 0 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::serviceStop May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: [1779910472919] ControllerTidal::stop May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::stop May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand stop May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand stop took 24 milliseconds May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::play index undefined May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::startPlaybackTimer May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: [1779910472945] ControllerTidal::clearAddPlayTrack May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: Getting stream with soundQuality HI_RES May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 20 milliseconds May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=play&N=1 200 (64ms) (action=playQueuePosition, command=play) May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 50% (POTENTIOMETER). May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=50 (action=setVolume, volumePercent=50) May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 6 milliseconds May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 27 21:34:32 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 51ms May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 50 May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume50 May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=50 200 (100ms) (action=setVolume, volumePercent=50) May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 58% (POTENTIOMETER). May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=58 (action=setVolume, volumePercent=58) May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 58 May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume58 May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=58 200 (63ms) (action=setVolume, volumePercent=58) May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:33 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:34 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:34 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:34 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:34 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:35 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:35 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:35 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:35 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] -> POST /api/internal/speaker/events (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: getStreamUrl took 3575 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand stop May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand stop took 1 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand clear May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces system playlist update May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: Ignoring MPD Status Update May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand clear took 1 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4MDRhYTYwMmZjNDE0OWY5MTI3ZWMxMWU2YTQ5YTczZl82MS5tcDQ/0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==" May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: error: updateQueue error: null May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 2ms May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces system playlist update May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: Ignoring MPD Status Update May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4MDRhYTYwMmZjNDE0OWY5MTI3ZWMxMWU2YTQ5YTczZl82MS5tcDQ/0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==" took 2 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand play May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 2ms May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand play took 1 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 19 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 1 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 2 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4MDRhYTYwMmZjNDE0OWY5MTI3ZWMxMWU2YTQ5YTczZl82MS5tcDQ/0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==","trackType":"tidal"} May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 1 May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus stop May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 25ms May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 2 milliseconds May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4MDRhYTYwMmZjNDE0OWY5MTI3ZWMxMWU2YTQ5YTczZl82MS5tcDQ/0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==","trackType":"tidal"} May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 1 May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus play May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: Received an update from plugin. extracting info from payload May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 37ms May 27 21:34:36 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] <- POST /api/internal/speaker/events 200 (943ms) (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] -> PUT /api/internal/speaker/snapshot (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 50% (POTENTIOMETER). May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=50 (action=setVolume, volumePercent=50) May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 50 May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume50 May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:37 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=50 200 (67ms) (action=setVolume, volumePercent=50) May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] <- PUT /api/internal/speaker/snapshot 200 (1552ms) (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Pot switch is off; requesting PAUSE + local volume 0%. May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE requested PAUSE. May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=pause (action=executeCommand, command=pause) May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::servicePause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [1779910478904] ControllerTidal::pause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand pause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand pause took 3 milliseconds May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 2 milliseconds May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=pause 200 (14ms) (action=executeCommand, command=pause) May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 6 milliseconds May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3461,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"811 Kbps","isStreaming":false,"title":"0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4MDRhYTYwMmZjNDE0OWY5MTI3ZWMxMWU2YTQ5YTczZl82MS5tcDQ/0.flac?token=1779914076~MWYzYzdkMjRiMjVjYjE5MmUxNTcwZjc4MWZkMzAyZjlhMWY2MjEzYg==","trackType":"tidal"} May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 1 May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService pause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus pause May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 34ms May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 0% (POT_SWITCH_OFF). May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=0 (action=setVolume, volumePercent=0) May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:38 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:39 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=0 200 (61ms) (action=setVolume, volumePercent=0) May 27 21:34:39 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:39 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:39 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] Quick off-on gesture requested SKIP_NEXT. May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=play&N=2 (action=playQueuePosition, command=play) May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio play at index 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPlay May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::play index 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stop May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::updateTrackBlock May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrackBlock May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::serviceStop May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 1 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::serviceStop May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [1779910480446] ControllerTidal::stop May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::stop May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand stop May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand stop took 26 milliseconds May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::play index undefined May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::startPlaybackTimer May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [1779910480476] ControllerTidal::clearAddPlayTrack May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: Getting stream with soundQuality HI_RES May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 8 milliseconds May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=play&N=2 200 (69ms) (action=playQueuePosition, command=play) May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 50% (POTENTIOMETER). May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=50 (action=setVolume, volumePercent=50) May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 6 milliseconds May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 37ms May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 50 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume50 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=50 200 (90ms) (action=setVolume, volumePercent=50) May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 72% (POTENTIOMETER). May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=72 (action=setVolume, volumePercent=72) May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 72 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume72 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=72 200 (79ms) (action=setVolume, volumePercent=72) May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:40 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:41 ode-spk-grefsen-04 tailscaled[629]: ssh-conn-20260527T193438-deffd160e5: handling conn: 100.119.250.89:53915->volumio@100.77.164.84:22 May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::getQueue May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getQueue May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] -> PUT /api/internal/speaker/snapshot (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: getStreamUrl took 873 milliseconds May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand stop May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand stop took 1 milliseconds May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand clear May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces system playlist update May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: Ignoring MPD Status Update May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand clear took 1 milliseconds May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQwYjRhNTdkYTAxNjYzNDA3ZGZiYTNkOGRkNjdkYmEyNC5tcDQ/0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==" May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: error: updateQueue error: null May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 2ms May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQwYjRhNTdkYTAxNjYzNDA3ZGZiYTNkOGRkNjdkYmEyNC5tcDQ/0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==" took 1 milliseconds May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand play May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces system playlist update May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: Ignoring MPD Status Update May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand play took 2 milliseconds May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 2ms May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:41 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:42 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:42 ode-spk-grefsen-04 volumio[1103]: info: [ode-client] <- PUT /api/internal/speaker/snapshot 200 (1523ms) (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:42 ode-spk-grefsen-04 volumio[1103]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:34:42 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: ssh-conn-20260527T193438-deffd160e5: starting session: sess-20260527T193442-b4a2029ab0 May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: ssh-session(sess-20260527T193442-b4a2029ab0): handling new SSH connection from jakobhn@github (100.119.250.89) to ssh-user "volumio" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: ssh-session(sess-20260527T193442-b4a2029ab0): access granted to jakobhn@github as ssh-user "volumio" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: audit: SSH login: user=volumio uid=1000 from=100.119.250.89 ts_user=jakobhn@github node=jakobs-macbook-pro-1.tail56347c.ts.net. May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: ssh-session(sess-20260527T193442-b4a2029ab0): starting non-pty command: [/usr/sbin/tailscaled be-child ssh --login-shell=/bin/bash --uid=1000 --gid=1000 --groups=1000,4,7,20,24,25,29,30,44,46,102,103,108,994,993 --local-user=volumio --home-dir=/home/volumio --remote-user=jakobhn@github --remote-ip=100.119.250.89 --has-tty=false --tty-name= --force-v1-behavior --cmd=set -eu May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: backup="/data/configuration/plugins.json.ode-g04-ab-multiroom-$(date +%Y%m%dT%H%M%S).bak" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: cp /data/configuration/plugins.json "$backup" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: printf "backup=%s\n" "$backup" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: node - <<"NODE" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: const fs=require("fs"); const p="/data/configuration/plugins.json"; const j=JSON.parse(fs.readFileSync(p,"utf8")); May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: function off(cat,name){ if(!j[cat]||!j[cat][name]) return; j[cat][name].enabled={type:"boolean",value:false}; j[cat][name].status={type:"string",value:"STOPPED"}; } May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: off("audio_interface","multiroom"); off("system_controller","volumiodiscovery"); May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: fs.writeFileSync(p, JSON.stringify(j,null,2)); May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: NODE May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: volumio pause >/dev/null 2>&1 || true May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: volumio volume 0 >/dev/null 2>&1 || true May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: sudo -n systemctl restart volumio May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: sleep 18 May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: printf "== plugin status after multiroom off ==\n" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: node - <<"NODE" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: const fs=require("fs"); const j=JSON.parse(fs.readFileSync("/data/configuration/plugins.json","utf8")); May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: for (const [cat,name] of [["audio_interface","multiroom"],["system_controller","volumiodiscovery"],["system_controller","ode_speaker_bridge"],["system_hardware","ode_hardware_controls"]]) console.log(cat,name,JSON.stringify({enabled:j[cat]?.[name]?.enabled,status:j[cat]?.[name]?.status})); May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: NODE May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: printf "== top/helper ==\n"; ps -eo pid,etimes,pcpu,pmem,args --sort=-pcpu | head -12; ps -eo pid,etimes,pcpu,pmem,args | awk "/[o]de_hardware_io.py/ {print}" || true May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: printf "== gateway ping ==\n"; gw=$(ip route | awk "/default/ {print \$3; exit}"); ping -c 20 -W 1 "$gw" || true May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: printf "== playback timings multiroom off ==\n" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: python3 - <<"PY" May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: import subprocess, time, json, urllib.request May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: def status(): May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: p=subprocess.run(["volumio","status"],stdout=subprocess.PIPE,stderr=subprocess.PIPE,text=True,timeout=10) May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: try: return json.loads(p.stdout) May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: except Exception: return {"raw":(p.stdout or p.stderr)[:300]} May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: def rest(path): May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: start=time.monotonic() May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: with urllib.request.urlopen("http://127.0.0.1:3000"+path,timeout=45) as r: body=r.read().decode() May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: return time.monotonic()-start, body May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: subprocess.run(["volumio","volume","45"],stdout=subprocess.PIPE,stderr=subprocess.PIPE,text=True,timeout=10) May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: print("before", {k:status().get(k) for k in ["status","title","position","volume","uri","trackType"]}) May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: for label,path in [("playN0","/api/v1/commands/?cmd=play&N=0"),("next","/api/v1/commands/?cmd=next")]: May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: e,b=rest(path); print(label,"return",f"{e:.3f}s",b[:100].replace("\n"," ")) May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: start=time.monotonic(); last=None May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: while time.monotonic()-start < 30: May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: s=status(); compact={k:s.get(k) for k in ["status","title","position","volume","uri","trackType"]} May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: if compact != last: May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: print(label,"poll",f"{time.monotonic()-start:.3f}s",compact) May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: last=compact May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: if s.get("status") == "play" and time.monotonic()-start > 1: May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: break May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: time.sleep(0.5) May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: PY May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: printf "== recent filtered logs ==\n"; journalctl -u volumio --since "3 minutes ago" --no-pager | grep -Ei "MRS|multiroom|volumiodiscovery|ode-hardware|tidal|updateQueue|error|decoder|packet|partial|softmaster" | tail -140 || true May 27 21:34:42 ode-spk-grefsen-04 tailscaled[629]: ] May 27 21:34:42 ode-spk-grefsen-04 systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. May 27 21:34:43 ode-spk-grefsen-04 systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... May 27 21:34:43 ode-spk-grefsen-04 systemd-logind[628]: New session c7 of user volumio. May 27 21:34:43 ode-spk-grefsen-04 systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. May 27 21:34:43 ode-spk-grefsen-04 systemd[1]: Starting user@1000.service - User Manager for UID 1000... May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:43 ode-spk-grefsen-04 (systemd)[4789]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 21 milliseconds May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 2 milliseconds May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 3 milliseconds May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQwYjRhNTdkYTAxNjYzNDA3ZGZiYTNkOGRkNjdkYmEyNC5tcDQ/0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==","trackType":"tidal"} May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 2 May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus stop May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 28ms May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 3 milliseconds May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQwYjRhNTdkYTAxNjYzNDA3ZGZiYTNkOGRkNjdkYmEyNC5tcDQ/0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==","trackType":"tidal"} May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 2 May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService play May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus play May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: Received an update from plugin. extracting info from payload May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 45ms May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 67% (POTENTIOMETER). May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=67 (action=setVolume, volumePercent=67) May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 67 May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume67 May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=67 200 (62ms) (action=setVolume, volumePercent=67) May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Queued start job for default target default.target. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Created slice app.slice - User Application Slice. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Reached target paths.target - Paths. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Reached target timers.target - Timers. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Listening on dirmngr.socket - GnuPG network certificate management daemon. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Reached target sockets.target - Sockets. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Reached target basic.target - Basic System. May 27 21:34:43 ode-spk-grefsen-04 systemd[1]: Started user@1000.service - User Manager for UID 1000. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Started mpris-proxy.service - Bluetooth mpris proxy. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Reached target default.target - Main User Target. May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: Startup finished in 737ms. May 27 21:34:43 ode-spk-grefsen-04 systemd[1]: Started session-c7.scope - Session c7 of User volumio. May 27 21:34:43 ode-spk-grefsen-04 mpris-proxy[4806]: Can't get on session bus May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE May 27 21:34:43 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:43 ode-spk-grefsen-04 systemd[4789]: mpris-proxy.service: Failed with result 'exit-code'. May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 64% (POTENTIOMETER). May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=64 (action=setVolume, volumePercent=64) May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 64 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume64 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] <- GET /api/v1/commands/?cmd=volume&volume=64 200 (64ms) (action=setVolume, volumePercent=64) May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volumio pause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::servicePause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: [1779910484690] ControllerTidal::pause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand pause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: ---------------------------- MPD announces state update: player May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand pause took 2 milliseconds May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::getState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand status May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand status took 3 milliseconds May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: sendMpdCommand playlistinfo took 1 milliseconds May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: verbose: ControllerMpd::parseTrackInfo May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: ControllerMpd::pushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::servicePushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CorePlayQueue::getTrack 2 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":1719,"duration":156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"828 Kbps","isStreaming":false,"title":"0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQwYjRhNTdkYTAxNjYzNDA3ZGZiYTNkOGRkNjdkYmEyNC5tcDQ/0.flac?token=1779914080~NDhiNmI3M2QyOTRkYzVlODI4OWRlYjg0YjkyZjY2YjQzNjYzMTYxMA==","trackType":"tidal"} May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: verbose: CURRENT POSITION 2 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState stateService pause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::syncState currentStatus pause May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::stPlaybackTimer May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: ------------------------------ 37ms May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 0 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume0 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:44 ode-spk-grefsen-04 sudo[4831]: volumio : PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/systemctl restart volumio May 27 21:34:44 ode-spk-grefsen-04 sudo[4831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioGetState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: [ode-hardware-controls] HARDWARE set local volume to 55% (POTENTIOMETER). May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: [volumio-rest] -> GET /api/v1/commands/?cmd=volume&volume=55 (action=setVolume, volumePercent=55) May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: ---------------------------- Client requests Volume 55 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: VolumeController::SetAlsaVolume55 May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreStateMachine::pushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: CoreCommandRouter::volumioPushState May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output update for this device May 27 21:34:44 ode-spk-grefsen-04 volumio[1103]: info: MRS: Pushing multiroomSync output May 27 21:34:44 ode-spk-grefsen-04 systemd[1]: Started dynamicswap.service - dynamicswap service. May 27 21:34:44 ode-spk-grefsen-04 systemd[1]: Stopping volumio.service - Volumio Backend Module... May 27 21:34:45 ode-spk-grefsen-04 systemd[1]: dynamicswap.service: Deactivated successfully. May 27 21:34:45 ode-spk-grefsen-04 systemd[1]: volumio.service: Deactivated successfully. May 27 21:34:45 ode-spk-grefsen-04 systemd[1]: Stopped volumio.service - Volumio Backend Module. May 27 21:34:45 ode-spk-grefsen-04 systemd[1]: volumio.service: Consumed 12min 24.750s CPU time. May 27 21:34:45 ode-spk-grefsen-04 systemd[1]: Started volumio.service - Volumio Backend Module. May 27 21:34:45 ode-spk-grefsen-04 sudo[4831]: pam_unix(sudo:session): session closed for user root May 27 21:34:45 ode-spk-grefsen-04 volumio-remote-updater[634]: [2026-05-27 21:34:45] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 27 21:34:45 ode-spk-grefsen-04 volumio-remote-updater[634]: [2026-05-27 21:34:45] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 27 21:34:48 ode-spk-grefsen-04 volumio[4844]: info: ------------------------------------------- May 27 21:34:48 ode-spk-grefsen-04 volumio[4844]: info: ----- Volumio3 ---- May 27 21:34:48 ode-spk-grefsen-04 volumio[4844]: info: ------------------------------------------- May 27 21:34:48 ode-spk-grefsen-04 volumio[4844]: info: ----- System startup ---- May 27 21:34:48 ode-spk-grefsen-04 volumio[4844]: info: ------------------------------------------- May 27 21:34:49 ode-spk-grefsen-04 volumio[4844]: info: MYVOLUMIO Environment detected May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Plugin folders cleanup May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning into folder /volumio/app/plugins/ May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category audio_interface May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category miscellanea May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category music_service May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category plugins.json May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category system_controller May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category user_interface May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning into folder /data/plugins/ May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category system_controller May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Scanning category system_hardware May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Plugin folders cleanup completed May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: ------------------------------------------- May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: ----- Core plugins startup ---- May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: ------------------------------------------- May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Loading plugins from folder /volumio/app/plugins/ May 27 21:34:50 ode-spk-grefsen-04 volumio-remote-updater[634]: [2026-05-27 21:34:50] [connect] Successful connection May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin upnp to MyMusic Plugins May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin airplay_emulation to MyMusic Plugins May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin upnp_browser to MyMusic Plugins May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Loading plugins from folder /data/plugins/ May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "system"... May 27 21:34:50 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "appearance"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "network"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Refreshing Cached IP Addresses May 27 21:34:52 ode-spk-grefsen-04 sudo[4868]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 27 21:34:52 ode-spk-grefsen-04 sudo[4868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:52 ode-spk-grefsen-04 sudo[4870]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 27 21:34:52 ode-spk-grefsen-04 sudo[4870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "services"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Plugin volumio5onboarding is not enabled May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "alsa_controller"... May 27 21:34:52 ode-spk-grefsen-04 sudo[4870]: pam_unix(sudo:session): session closed for user root May 27 21:34:52 ode-spk-grefsen-04 sudo[4886]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 27 21:34:52 ode-spk-grefsen-04 sudo[4886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:52 ode-spk-grefsen-04 sudo[4868]: pam_unix(sudo:session): session closed for user root May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "wizard"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "networkfs"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Starting Udev Watcher for removable devices May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Ignoring mount for partition: boot May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Ignoring mount for partition: volumio May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Ignoring mount for partition: volumio_data May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "volumio_command_line_client"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "upnp"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: [1779910492736] Starting Upmpd Daemon May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "my_music"... May 27 21:34:52 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "mpd"... May 27 21:34:53 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "upnp_browser"... May 27 21:34:53 ode-spk-grefsen-04 sudo[4886]: pam_unix(sudo:session): session closed for user root May 27 21:34:53 ode-spk-grefsen-04 tailscaled[629]: portmapper: saw UPnP type WANIPConnection1 at http://192.168.0.1:35322/rootDesc.xml; G403 (D-Link Corporation), method=single May 27 21:34:55 ode-spk-grefsen-04 volumio[4844]: info: Starting UPNP Browser May 27 21:34:55 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "ode_hardware_controls"... May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Ode hardware-controls plugin initialized May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "alarm-clock"... May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Plugin airplay_emulation is not enabled May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "last_100"... May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "webradio"... May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "i2s_dacs"... May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Plugin volumiodiscovery is not enabled May 27 21:34:56 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "ode_speaker_bridge"... May 27 21:34:56 ode-spk-grefsen-04 tailscaled[629]: portmapper: UPnP returned unspecified external IP 0.0.0.0 May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Ode speaker bridge plugin initialized May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "outputs"... May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Plugin albumart is not enabled May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Plugin example_plugin is not enabled May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "inputs"... May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "updater_comm"... May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Plugin mpdemulation is not enabled May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "rest_api"... May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Loading plugin "websocket"... May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Starting Socket.io Server version 1.7.4 May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Loading i18n strings for locale en May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: Updating browse sources language May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::initPlayerControls May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: Express server listening on port 3000 May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: [Metrics] WebUI: 10s 325.68ms May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::resetVolumioState May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::getcurrentVolume May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioRetrievevolume May 27 21:34:57 ode-spk-grefsen-04 volumio[4844]: info: Volumio Network Manager: Network status updated: 2 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::pushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioPushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::updateTrackBlock May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrackBlock May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioRetrievevolume May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Reloading queue from file May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::setRepeat null single undefined May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::pushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioPushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::setRandom null May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::pushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioPushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Setting Device type: Raspberry PI May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Completed loading Core Plugins May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Preparing to generate the ALSA configuration file May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::pushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioPushState May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: USB Boot Capable - System SBC Revision found in cpuinfo: 902120 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Reading ALSA contributions from plugins. May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Asound.conf file written May 27 21:34:58 ode-spk-grefsen-04 sudo[4925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 27 21:34:58 ode-spk-grefsen-04 sudo[4925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:58 ode-spk-grefsen-04 sudo[4925]: pam_unix(sudo:session): session closed for user root May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Output device has changed, restarting MPD May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: ___________ START PLUGINS ___________ May 27 21:34:58 ode-spk-grefsen-04 sudo[4931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 27 21:34:58 ode-spk-grefsen-04 sudo[4931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:58 ode-spk-grefsen-04 sudo[4931]: pam_unix(sudo:session): session closed for user root May 27 21:34:58 ode-spk-grefsen-04 sudo[4933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 27 21:34:58 ode-spk-grefsen-04 sudo[4933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: ControllerMpd::onStart: Initializing MPD May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Creating MPD Configuration file May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 27 21:34:58 ode-spk-grefsen-04 sudo[4937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: [1779910498437] CoreMusicLibrary::Adding element Media Servers May 27 21:34:58 ode-spk-grefsen-04 sudo[4937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:58 ode-spk-grefsen-04 systemd[1]: Stopping mpd.service - Music Player Daemon... May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 21:34:58 ode-spk-grefsen-04 sudo[4937]: pam_unix(sudo:session): session closed for user root May 27 21:34:58 ode-spk-grefsen-04 sudo[4939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 27 21:34:58 ode-spk-grefsen-04 sudo[4939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: UPNP Browser: Client initialized successfully May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: [1779910498504] CoreMusicLibrary::Adding element Last_100 May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: [1779910498511] CoreMusicLibrary::Adding element Webradio May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Initializing BBC Radios May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:58 ode-spk-grefsen-04 volumio[4844]: info: Volumio Calling Home May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] GPIO lane: Legacy GPIO polling, ADC volume reads, and LED writes are configured for the Volumio hardware loop. May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] I2S status: SATISFIED (Required I2S DAC profile is already active on the speaker.) May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Volume status: SATISFIED (Required Volumio volume mixer configuration is already active.) May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: MPD Permissions set May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: MPD Permissions set May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: Volumio called home May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetQueue May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::getQueue May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getQueue May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: [ode-client] -> PUT /api/internal/speaker/snapshot (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:34:59 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 21:35:00 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Hardware runtime loop started (poll=500ms, heartbeat=30000ms). May 27 21:35:00 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:00 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:00 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Runtime usage mode switched to STANDARD_OPERATION. May 27 21:35:00 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:00 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:00 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] -> GET /api/internal/speaker/settings (speakerId=spk_grefsen_04). May 27 21:35:01 ode-spk-grefsen-04 volumio[4844]: info: [ode-client] <- PUT /api/internal/speaker/snapshot 200 (1527ms) (action=putSnapshot, speakerId=spk_grefsen_04, queueRevision=song-set:2026-05-27T19:08:28.796Z:window:evening) May 27 21:35:01 ode-spk-grefsen-04 volumio[4844]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:35:01 ode-spk-grefsen-04 volumio[4844]: info: [ode-speaker-bridge] Deferred bridge runtime startup completed. May 27 21:35:01 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] <- GET /api/internal/speaker/settings 200 (1286ms, speakerId=spk_grefsen_04). May 27 21:35:01 ode-spk-grefsen-04 volumio[4844]: info: [ode-client] -> POST /api/internal/speaker/health (action=postHealthSamples) May 27 21:35:01 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Tick heartbeat #1 (duration=1755ms, skipped=3, errors=0, potSwitch=false, slideSwitch=true, volumeLocked=false, intentGate=startup, potRaw=0). May 27 21:35:01 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Deferred hardware runtime startup completed. May 27 21:35:02 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:02 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:02 ode-spk-grefsen-04 volumio-remote-updater[634]: [2026-05-27 21:35:02] [connect] Successful connection May 27 21:35:02 ode-spk-grefsen-04 volumio-remote-updater[634]: [2026-05-27 21:35:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1779910502 101 May 27 21:35:02 ode-spk-grefsen-04 volumio[4844]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 May 27 21:35:02 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:02 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:02 ode-spk-grefsen-04 sudo[4991]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 27 21:35:02 ode-spk-grefsen-04 sudo[4993]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 27 21:35:02 ode-spk-grefsen-04 sudo[4991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:35:02 ode-spk-grefsen-04 sudo[4993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:35:02 ode-spk-grefsen-04 sudo[4995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 27 21:35:02 ode-spk-grefsen-04 sudo[4995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:35:02 ode-spk-grefsen-04 sudo[4993]: pam_unix(sudo:session): session closed for user root May 27 21:35:03 ode-spk-grefsen-04 volumio[4844]: info: [ode-client] <- POST /api/internal/speaker/health 200 (1101ms) (action=postHealthSamples) May 27 21:35:03 ode-spk-grefsen-04 sudo[4995]: pam_unix(sudo:session): session closed for user root May 27 21:35:03 ode-spk-grefsen-04 volumio[4844]: info: Upmpdcli Daemon Started May 27 21:35:03 ode-spk-grefsen-04 sudo[4991]: pam_unix(sudo:session): session closed for user root May 27 21:35:03 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:03 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:03 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:03 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: mpd.service: Deactivated successfully. May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: Stopped mpd.service - Music Player Daemon. May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: mpd.service: Consumed 14.327s CPU time. May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: mpd.socket: Deactivated successfully. May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: error: Upnp client error: Error: read ECONNRESET May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: error: Upnp client error: Error: read ECONNRESET May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 27 21:35:04 ode-spk-grefsen-04 systemd[1]: Starting mpd.service - Music Player Daemon... May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetQueue May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::getQueue May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getQueue May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:35:04 ode-spk-grefsen-04 sudo[5021]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 27 21:35:04 ode-spk-grefsen-04 sudo[5021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 27 21:35:04 ode-spk-grefsen-04 sudo[5021]: pam_unix(sudo:session): session closed for user root May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:04 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:05 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:05 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:05 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:05 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:06 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:06 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:06 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:06 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:07 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:07 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:07 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:07 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:08 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:08 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:08 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:08 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetQueue May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::getQueue May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getQueue May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: [ode-client] -> POST /api/internal/speaker/events (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Holding READY during startup guard (10512ms/60000ms). May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: [ode-client] <- POST /api/internal/speaker/events 200 (460ms) (action=postEvent, speakerId=spk_grefsen_04, eventType=queue_activated) May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:09 ode-spk-grefsen-04 volumio[4844]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:35:10 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:10 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:10 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:10 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:11 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:11 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:11 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:11 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:12 ode-spk-grefsen-04 mpd[5023]: 2026-05-27T21:35:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 27 21:35:12 ode-spk-grefsen-04 systemd[1]: Started mpd.service - Music Player Daemon. May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:12 ode-spk-grefsen-04 sudo[4933]: pam_unix(sudo:session): session closed for user root May 27 21:35:12 ode-spk-grefsen-04 sudo[4939]: pam_unix(sudo:session): session closed for user root May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: Completed starting Core Plugins May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: ------------------------------------------- May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: ----- MyVolumio plugins startup ---- May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: ------------------------------------------- May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Fetching plans data.... May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: error: MPD error: The expression evaluated to a falsy value: May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: assert.ok(self.idling) May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: error: The expression evaluated to a falsy value: May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: assert.ok(self.idling) May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: MPD running with PID5023 May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: ,establishing connection May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: error: updateQueue error: null May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: error: updateQueue error: null May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:12 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:13 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:13 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:13 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:13 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetQueue May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::getQueue May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getQueue May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:14 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:15 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:15 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:15 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Holding READY during startup guard (16010ms/60000ms). May 27 21:35:15 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:15 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:16 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:16 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:16 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:16 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:17 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:17 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:17 ode-spk-grefsen-04 volumio[4844]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 27 21:35:17 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:17 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:18 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:18 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:18 ode-spk-grefsen-04 tailscaled[629]: portmapper: PMP probe failed due result code: {OpCode:128 ResultCode:NetworkFailure SecondsSinceEpoch:48260 MappingValidSeconds:0 InternalPort:0 ExternalPort:0 PublicAddr:invalid IP} May 27 21:35:18 ode-spk-grefsen-04 tailscaled[629]: control: NetInfo: NetInfo{varies=true ipv6=false ipv6os=false udp=true icmpv4=false derp=#28 portmap=UC link="" firewallmode="ipt-default"} May 27 21:35:18 ode-spk-grefsen-04 tailscaled[629]: portmapper: failed to get PCP mapping: PCP response not ok, code 7 May 27 21:35:18 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:18 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetQueue May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::getQueue May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getQueue May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:19 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:20 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:20 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:20 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:20 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:20 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Holding READY during startup guard (21506ms/60000ms). May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin bluetooth to MyMusic Plugins May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin multiroom to MyMusic Plugins May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin metavolumio to MyMusic Plugins May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin cd_controller to MyMusic Plugins May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin qobuzconnect to MyMusic Plugins May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin smart_inputs to MyMusic Plugins May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: Adding plugin tidalconnect to MyMusic Plugins May 27 21:35:21 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: Starting MyVolumio Remote Streaming Endpoints May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: MyVolumio login type: Token May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 27 21:35:24 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: Streaming services startup May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: Starting Streaming Daemon May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 27 21:35:26 ode-spk-grefsen-04 sudo[5063]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart volumio-streaming-daemon.service May 27 21:35:26 ode-spk-grefsen-04 sudo[5063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: ---------------------------- Client requests Volume 45 May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: VolumeController::SetAlsaVolume45 May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::pushState May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioPushState May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetQueue May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::getQueue May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getQueue May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: [ode-speaker-bridge] posted heartbeat via REST_FALLBACK for spk_grefsen_04. May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: [ode-hardware-controls] Holding READY during startup guard (27275ms/60000ms). May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:26 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:26 ode-spk-grefsen-04 systemd[1]: Started volumioStreaming.service - VolumioStreamingService. May 27 21:35:26 ode-spk-grefsen-04 sudo[5063]: pam_unix(sudo:session): session closed for user root May 27 21:35:27 ode-spk-grefsen-04 sudo[5075]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/rm -f /tmp/hls/* May 27 21:35:27 ode-spk-grefsen-04 sudo[5075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 27 21:35:27 ode-spk-grefsen-04 sudo[5075]: pam_unix(sudo:session): session closed for user root May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:27 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioGetState May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: ---------------------------- Client requests Volumio play at index 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreCommandRouter::volumioPlay May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::play index 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::stop May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::play index undefined May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CoreStateMachine::startPlaybackTimer May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: info: CorePlayQueue::getTrack 0 May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: TypeError: Cannot read properties of undefined (reading 'clearAddPlayTrack') May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: at Promise._successFn (/volumio/app/statemachine.js:1027:33) May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) May 27 21:35:28 ode-spk-grefsen-04 volumio[4844]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 21:35:33 ode-spk-grefsen-04 sudo[5125]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-27 21:34' May 27 21:35:33 ode-spk-grefsen-04 sudo[5125]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"