Oct 15 10:01:20 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:01:20 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:20 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 10:01:20 volumio volumio[1230]: info: CoreCommandRouter::volumioPlay Oct 15 10:01:20 volumio volumio[1230]: info: CoreStateMachine::play index undefined Oct 15 10:01:20 volumio volumio[1230]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:01:20 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:20 volumio volumio[1230]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:01:20 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:20 volumio volumio[1230]: info: ControllerMpd::resume Oct 15 10:01:20 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:01:20 volumio volumio[1230]: info: sendMpdCommand play took 1 milliseconds Oct 15 10:01:20 volumio volumio[1230]: info: ControllerMpd::getState Oct 15 10:01:20 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:01:20 volumio volumio[1230]: info: sendMpdCommand status took 0 milliseconds Oct 15 10:01:20 volumio volumio[1230]: verbose: ControllerMpd::parseState Oct 15 10:01:20 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:20 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:20 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:20 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:20 volumio volumio[1230]: 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} Oct 15 10:01:20 volumio volumio[1230]: verbose: CURRENT POSITION 1 Oct 15 10:01:20 volumio volumio[1230]: info: CoreStateMachine::syncState stateService stop Oct 15 10:01:20 volumio volumio[1230]: info: CoreStateMachine::syncState currentStatus pause Oct 15 10:01:20 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:20 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:20 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:20 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:20 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:20.703+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=25497 volume=38 Oct 15 10:01:20 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:20.704+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:20 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:20.705+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=25497 volume=38 Oct 15 10:01:20 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:20.706+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:23 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:01:23 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:23 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 10:01:23 volumio volumio[1230]: info: CoreCommandRouter::volumioPlay Oct 15 10:01:23 volumio volumio[1230]: info: CoreStateMachine::play index undefined Oct 15 10:01:23 volumio volumio[1230]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:01:23 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:23 volumio volumio[1230]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:01:23 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:23 volumio volumio[1230]: info: ControllerMpd::resume Oct 15 10:01:23 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:01:23 volumio volumio[1230]: info: sendMpdCommand play took 1 milliseconds Oct 15 10:01:23 volumio volumio[1230]: info: ControllerMpd::getState Oct 15 10:01:23 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:01:23 volumio volumio[1230]: info: sendMpdCommand status took 1 milliseconds Oct 15 10:01:23 volumio volumio[1230]: verbose: ControllerMpd::parseState Oct 15 10:01:23 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:23 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:23 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:23 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:23 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:23 volumio volumio[1230]: 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} Oct 15 10:01:23 volumio volumio[1230]: verbose: CURRENT POSITION 1 Oct 15 10:01:23 volumio volumio[1230]: info: CoreStateMachine::syncState stateService stop Oct 15 10:01:23 volumio volumio[1230]: info: CoreStateMachine::syncState currentStatus pause Oct 15 10:01:23 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:23 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:23 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:23 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:23.708+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=28499 volume=38 Oct 15 10:01:23 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:23.709+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:23 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:23.709+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=28499 volume=38 Oct 15 10:01:23 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:23.710+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:25 volumio volumio[1230]: info: CoreCommandRouter::volumioGetQueue Oct 15 10:01:25 volumio volumio[1230]: info: CoreStateMachine::getQueue Oct 15 10:01:25 volumio volumio[1230]: info: CorePlayQueue::getQueue Oct 15 10:01:26 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:01:26 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:26 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 10:01:26 volumio volumio[1230]: info: CoreCommandRouter::volumioPlay Oct 15 10:01:26 volumio volumio[1230]: info: CoreStateMachine::play index undefined Oct 15 10:01:26 volumio volumio[1230]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:01:26 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:26 volumio volumio[1230]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:01:26 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:26 volumio volumio[1230]: info: ControllerMpd::resume Oct 15 10:01:26 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:01:26 volumio volumio[1230]: info: sendMpdCommand play took 1 milliseconds Oct 15 10:01:26 volumio volumio[1230]: info: ControllerMpd::getState Oct 15 10:01:26 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:01:26 volumio volumio[1230]: info: sendMpdCommand status took 1 milliseconds Oct 15 10:01:26 volumio volumio[1230]: verbose: ControllerMpd::parseState Oct 15 10:01:26 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:26 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:26 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:26 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:26 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:26 volumio volumio[1230]: 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} Oct 15 10:01:26 volumio volumio[1230]: verbose: CURRENT POSITION 1 Oct 15 10:01:26 volumio volumio[1230]: info: CoreStateMachine::syncState stateService stop Oct 15 10:01:26 volumio volumio[1230]: info: CoreStateMachine::syncState currentStatus pause Oct 15 10:01:26 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:26 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:26 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:26 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:26.687+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=31251 volume=38 Oct 15 10:01:26 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:26.687+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:26 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:26.687+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=31251 volume=38 Oct 15 10:01:26 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:26.688+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:28 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:01:28 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:28 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 10:01:28 volumio volumio[1230]: info: CoreCommandRouter::volumioPlay Oct 15 10:01:28 volumio volumio[1230]: info: CoreStateMachine::play index undefined Oct 15 10:01:28 volumio volumio[1230]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:01:28 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:28 volumio volumio[1230]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:01:28 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:28 volumio volumio[1230]: info: ControllerMpd::resume Oct 15 10:01:28 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:01:28 volumio volumio[1230]: info: sendMpdCommand play took 0 milliseconds Oct 15 10:01:28 volumio volumio[1230]: info: ControllerMpd::getState Oct 15 10:01:28 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:01:28 volumio volumio[1230]: info: sendMpdCommand status took 1 milliseconds Oct 15 10:01:28 volumio volumio[1230]: verbose: ControllerMpd::parseState Oct 15 10:01:28 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:28 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:28 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:28 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:28 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:28 volumio volumio[1230]: 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} Oct 15 10:01:28 volumio volumio[1230]: verbose: CURRENT POSITION 1 Oct 15 10:01:28 volumio volumio[1230]: info: CoreStateMachine::syncState stateService stop Oct 15 10:01:28 volumio volumio[1230]: info: CoreStateMachine::syncState currentStatus pause Oct 15 10:01:28 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:28 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:28 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:28 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:28.189+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=32753 volume=38 Oct 15 10:01:28 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:28.189+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:28 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:28.190+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=32753 volume=38 Oct 15 10:01:28 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:28.191+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 10:01:36 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 10:01:39 volumio volumio[1230]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 15 10:01:39 volumio volumio[1230]: info: Preparing to save Alsa Options, stopping services first Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:01:39 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::volumioPause Oct 15 10:01:39 volumio volumio[1230]: info: CoreStateMachine::pause Oct 15 10:01:39 volumio volumio[1230]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"USB/BT DAC-1"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:01:39 volumio volumio[1230]: info: Setting mixer PCM for card USB/BT DAC-1 Oct 15 10:01:39 volumio vtcs[2766]: [2026-10-15 10:01:39.525] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Oct 15 10:01:39 volumio vtcs[2766]: [2026-10-15 10:01:39.532] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Oct 15 10:01:39 volumio sudo[2928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:01:39 volumio sudo[2928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 15 10:01:39 volumio volumio[1230]: info: Updating Volume Controller Parameters: Device: 5 Name: USB/BT DAC-1 Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 15 10:01:39 volumio volumio[1230]: info: Disabling external Volume Control Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 10:01:39 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Oct 15 10:01:39 volumio volumio[1230]: info: Preparing to generate the ALSA configuration file Oct 15 10:01:39 volumio systemd[1]: vtcs.service: Deactivated successfully. Oct 15 10:01:39 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Oct 15 10:01:39 volumio sudo[2928]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:39 volumio sudo[2939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:01:39 volumio sudo[2939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:39 volumio volumio[1230]: info: Asound.conf file unchanged, so no further update is needed Oct 15 10:01:39 volumio volumio[1230]: info: Output device has changed, restarting MPD Oct 15 10:01:39 volumio volumio[1230]: info: Output device has changed, restarting Shairport Sync Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:01:39 volumio sudo[2944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 10:01:39 volumio sudo[2944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:39 volumio sudo[2946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 10:01:39 volumio sudo[2946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:39 volumio sudo[2944]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:39 volumio sudo[2939]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:39 volumio volumio[1230]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 10:01:39 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 15 10:01:39 volumio sudo[2958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:01:39 volumio sudo[2958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:39 volumio sudo[2957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:01:39 volumio sudo[2957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:39 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 15 10:01:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 10:01:39 volumio systemd[1]: mpd.service: Consumed 1.354s CPU time. Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:01:39 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 15 10:01:39 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 10:01:39 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 10:01:39 volumio volumio[1230]: info: MPD Permissions set Oct 15 10:01:39 volumio volumio[1230]: info: VolumeController:: Volume=38 Mute =false Oct 15 10:01:39 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:39 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:39 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:39.799+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=44350 volume=38 Oct 15 10:01:39 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:39.800+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:39 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 10:01:39 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio sudo[2958]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:39 volumio sudo[2957]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:01:39 volumio volumio[1230]: info: Starting Shairport Sync Oct 15 10:01:39 volumio sudo[2981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 10:01:39 volumio sudo[2981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 15 10:01:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 15 10:01:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 10:01:39 volumio systemd[1]: shairport-sync.service: Consumed 1.520s CPU time. Oct 15 10:01:39 volumio sudo[2972]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 15 10:01:39 volumio sudo[2972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 10:01:39 volumio sudo[2972]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 10:01:40 volumio sudo[2981]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:40 volumio volumio[1230]: info: Shairport-Sync Started Oct 15 10:01:41 volumio mpd[2987]: 2026-10-15T10:01:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 15 10:01:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 15 10:01:41 volumio sudo[2946]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:41 volumio volumio[1230]: error: updateQueue error: null Oct 15 10:01:42 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:01:42 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:01:42 volumio volumio[1230]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:01:42 volumio volumio[1230]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:01:42 volumio sudo[3013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 15 10:01:42 volumio sudo[3013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:42 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Oct 15 10:01:42 volumio sudo[3013]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:42 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:01:42 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:01:42 volumio volumio[1230]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:01:42 volumio volumio[1230]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:01:42 volumio sudo[3027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 15 10:01:42 volumio sudo[3027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:01:42 volumio sudo[3027]: pam_unix(sudo:session): session closed for user root Oct 15 10:01:43 volumio volumio[1230]: info: Executing endpoint tc_getconfig Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 15 10:01:43 volumio vtcs[3016]: STARTING TidalConnect services, version: 1.6.1 Oct 15 10:01:43 volumio vtcs[3016]: STARTED TidalConnect services. Oct 15 10:01:43 volumio volumio[1230]: info: Executing endpoint tc_connect Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 15 10:01:43 volumio volumio[1230]: info: Connecting to TidalConnect Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::servicePushState Oct 15 10:01:43 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:43 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:43 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:43 volumio volumio[1230]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current carrot_radio Received tidalconnect Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::servicePushState Oct 15 10:01:43 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:43 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:43 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:43 volumio volumio[1230]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current carrot_radio Received tidalconnect Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.026+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=47354 volume=38 Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.027+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.029+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=47354 volume=38 Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.029+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 15 10:01:43 volumio volumio[1230]: info: CoreStateMachine::getcurrentVolume Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::volumioRetrievevolume Oct 15 10:01:43 volumio volumio[1230]: info: VolumeController:: Volume=38 Mute =false Oct 15 10:01:43 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:43 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:43 volumio volumio[1230]: info: CoreStateMachine::updateTrackBlock Oct 15 10:01:43 volumio volumio[1230]: info: CorePlayQueue::getTrackBlock Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::volumioRetrievevolume Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.613+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=48113 volume=38 Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.614+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:43 volumio volumio[1230]: info: VolumeController:: Volume=38 Mute =false Oct 15 10:01:43 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:43 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:43 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.644+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=48113 volume=38 Oct 15 10:01:43 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:43.644+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:45 volumio volumio[1230]: info: TidalConnect service started! Oct 15 10:01:45 volumio volumio[1230]: info: TidalConnect service started! Oct 15 10:01:48 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:01:48 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:48 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 10:01:48 volumio volumio[1230]: info: CoreCommandRouter::volumioPlay Oct 15 10:01:48 volumio volumio[1230]: info: CoreStateMachine::play index undefined Oct 15 10:01:48 volumio volumio[1230]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:01:48 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:48 volumio volumio[1230]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:01:48 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:48 volumio volumio[1230]: info: ControllerMpd::resume Oct 15 10:01:48 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:01:48 volumio volumio[1230]: info: sendMpdCommand play took 1 milliseconds Oct 15 10:01:48 volumio volumio[1230]: info: ControllerMpd::getState Oct 15 10:01:48 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:01:48 volumio volumio[1230]: info: sendMpdCommand status took 11 milliseconds Oct 15 10:01:48 volumio volumio[1230]: verbose: ControllerMpd::parseState Oct 15 10:01:48 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:48 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:48 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:01:48 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:48 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:48 volumio volumio[1230]: 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} Oct 15 10:01:48 volumio volumio[1230]: verbose: CURRENT POSITION 1 Oct 15 10:01:48 volumio volumio[1230]: info: CoreStateMachine::syncState stateService stop Oct 15 10:01:48 volumio volumio[1230]: info: CoreStateMachine::syncState currentStatus pause Oct 15 10:01:48 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:01:48 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:01:48 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:01:48 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:48.365+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=52867 volume=38 Oct 15 10:01:48 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:48.366+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=52867 volume=38 Oct 15 10:01:48 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:48.366+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:01:48 volumio volumio5-onboarding[1582]: time=2026-10-15T10:01:48.366+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:02:07 volumio volumio[1230]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 15 10:02:07 volumio volumio[1230]: info: Preparing to save Alsa Options, stopping services first Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:02:07 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::volumioPause Oct 15 10:02:07 volumio volumio[1230]: info: CoreStateMachine::pause Oct 15 10:02:07 volumio volumio[1230]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"USB/BT DAC-1"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:02:07 volumio volumio[1230]: info: Setting mixer PCM for card USB/BT DAC-1 Oct 15 10:02:07 volumio vtcs[3016]: [2026-10-15 10:02:07.306] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Oct 15 10:02:07 volumio vtcs[3016]: [2026-10-15 10:02:07.306] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Oct 15 10:02:07 volumio sudo[3107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:07 volumio sudo[3107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 15 10:02:07 volumio volumio[1230]: info: Updating Volume Controller Parameters: Device: 5 Name: USB/BT DAC-1 Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 15 10:02:07 volumio volumio[1230]: info: Disabling external Volume Control Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 10:02:07 volumio volumio[1230]: info: Preparing to generate the ALSA configuration file Oct 15 10:02:07 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Oct 15 10:02:07 volumio systemd[1]: vtcs.service: Deactivated successfully. Oct 15 10:02:07 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Oct 15 10:02:07 volumio sudo[3107]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:07 volumio sudo[3116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:07 volumio sudo[3116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:02:07 volumio sudo[3116]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 10:02:07 volumio volumio[1230]: info: Asound.conf file unchanged, so no further update is needed Oct 15 10:02:07 volumio volumio[1230]: info: Output device has changed, restarting MPD Oct 15 10:02:07 volumio volumio[1230]: info: Output device has changed, restarting Shairport Sync Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:02:07 volumio sudo[3129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 10:02:07 volumio sudo[3129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:07 volumio sudo[3129]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:07 volumio sudo[3131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 10:02:07 volumio sudo[3131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:07 volumio volumio[1230]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 10:02:07 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 15 10:02:07 volumio volumio[1230]: info: VolumeController:: Volume=38 Mute =false Oct 15 10:02:07 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:02:07 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:02:07 volumio sudo[3139]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:07 volumio sudo[3141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:07 volumio sudo[3139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:07 volumio sudo[3141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:02:07 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 15 10:02:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 10:02:07 volumio systemd[1]: mpd.service: Consumed 1.388s CPU time. Oct 15 10:02:07 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:07.560+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=71911 volume=38 Oct 15 10:02:07 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:07.560+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:02:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 15 10:02:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 10:02:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 10:02:07 volumio volumio[1230]: info: MPD Permissions set Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:07 volumio volumio[1230]: info: Starting Shairport Sync Oct 15 10:02:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 10:02:07 volumio sudo[3151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 10:02:07 volumio sudo[3151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 10:02:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 15 10:02:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 15 10:02:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 10:02:07 volumio systemd[1]: shairport-sync.service: Consumed 1.615s CPU time. Oct 15 10:02:07 volumio sudo[3141]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:07 volumio sudo[3139]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 10:02:07 volumio sudo[3151]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:07 volumio volumio[1230]: info: Shairport-Sync Started Oct 15 10:02:07 volumio sudo[3152]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 15 10:02:07 volumio sudo[3152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 10:02:07 volumio sudo[3152]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio volumio[1230]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 15 10:02:08 volumio volumio[1230]: info: Preparing to save Alsa Options, stopping services first Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:02:08 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::volumioPause Oct 15 10:02:08 volumio volumio[1230]: info: CoreStateMachine::pause Oct 15 10:02:08 volumio volumio[1230]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"USB/BT DAC-1"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:02:08 volumio volumio[1230]: info: Setting mixer PCM for card USB/BT DAC-1 Oct 15 10:02:08 volumio sudo[3184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:08 volumio sudo[3184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 15 10:02:08 volumio volumio[1230]: info: Updating Volume Controller Parameters: Device: 5 Name: USB/BT DAC-1 Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 15 10:02:08 volumio volumio[1230]: info: Disabling external Volume Control Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 10:02:08 volumio volumio[1230]: info: Preparing to generate the ALSA configuration file Oct 15 10:02:08 volumio sudo[3184]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio sudo[3192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:08 volumio sudo[3192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 10:02:08 volumio sudo[3192]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 10:02:08 volumio volumio[1230]: info: Asound.conf file unchanged, so no further update is needed Oct 15 10:02:08 volumio volumio[1230]: info: Output device has changed, restarting MPD Oct 15 10:02:08 volumio volumio[1230]: info: Output device has changed, restarting Shairport Sync Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio sudo[3203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:02:08 volumio sudo[3203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:08 volumio sudo[3203]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio sudo[3205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 10:02:08 volumio sudo[3205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:08 volumio volumio[1230]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 10:02:08 volumio sudo[3213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:08 volumio sudo[3213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:08 volumio volumio[1230]: info: MPD Permissions set Oct 15 10:02:08 volumio volumio[1230]: info: VolumeController:: Volume=38 Mute =false Oct 15 10:02:08 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:02:08 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:02:08 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 15 10:02:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 10:02:08 volumio systemd[1]: mpd.service: Consumed 1.024s CPU time. Oct 15 10:02:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 15 10:02:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 10:02:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 10:02:08 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:08.687+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=72946 volume=38 Oct 15 10:02:08 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:08.687+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:02:08 volumio sudo[3215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 15 10:02:08 volumio sudo[3215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 10:02:08 volumio volumio[1230]: info: Starting Shairport Sync Oct 15 10:02:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 10:02:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 10:02:08 volumio sudo[3226]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 10:02:08 volumio sudo[3226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 15 10:02:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 15 10:02:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 10:02:08 volumio systemd[1]: shairport-sync.service: Consumed 1.056s CPU time. Oct 15 10:02:08 volumio sudo[3215]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio sudo[3213]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio sudo[3227]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 15 10:02:08 volumio sudo[3227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 10:02:08 volumio sudo[3227]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 10:02:08 volumio sudo[3226]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:08 volumio volumio[1230]: info: Shairport-Sync Started Oct 15 10:02:09 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:02:09 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:09 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 10:02:09 volumio volumio[1230]: info: CoreCommandRouter::volumioPlay Oct 15 10:02:09 volumio volumio[1230]: info: CoreStateMachine::play index undefined Oct 15 10:02:09 volumio volumio[1230]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:02:09 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:09 volumio volumio[1230]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:02:09 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:09 volumio volumio[1230]: info: ControllerMpd::resume Oct 15 10:02:09 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:02:09 volumio volumio[1230]: info: CoreCommandRouter::volumioGetState Oct 15 10:02:09 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:09 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 10:02:09 volumio volumio[1230]: info: CoreCommandRouter::volumioPlay Oct 15 10:02:09 volumio volumio[1230]: info: CoreStateMachine::play index undefined Oct 15 10:02:09 volumio volumio[1230]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:02:09 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:09 volumio volumio[1230]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:02:09 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:09 volumio volumio[1230]: info: ControllerMpd::resume Oct 15 10:02:09 volumio volumio[1230]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:02:10 volumio mpd[3233]: 2026-10-15T10:02:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 15 10:02:10 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 15 10:02:10 volumio sudo[3205]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:10 volumio sudo[3131]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:10 volumio volumio[1230]: error: MPD error: The expression evaluated to a falsy value: Oct 15 10:02:10 volumio volumio[1230]: assert.ok(self.idling) Oct 15 10:02:10 volumio volumio[1230]: error: The expression evaluated to a falsy value: Oct 15 10:02:10 volumio volumio[1230]: assert.ok(self.idling) Oct 15 10:02:10 volumio volumio[1230]: error: updateQueue error: null Oct 15 10:02:10 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:02:10 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:02:10 volumio volumio[1230]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:02:10 volumio volumio[1230]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:02:10 volumio sudo[3261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 15 10:02:10 volumio sudo[3261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:02:10 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Oct 15 10:02:10 volumio sudo[3261]: pam_unix(sudo:session): session closed for user root Oct 15 10:02:10 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:02:10 volumio volumio[1230]: info: TidalConnect service stoped! Oct 15 10:02:10 volumio volumio[1230]: info: Executing endpoint tc_getconfig Oct 15 10:02:10 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 15 10:02:10 volumio vtcs[3264]: STARTING TidalConnect services, version: 1.6.1 Oct 15 10:02:10 volumio vtcs[3264]: STARTED TidalConnect services. Oct 15 10:02:10 volumio volumio[1230]: info: Executing endpoint tc_connect Oct 15 10:02:10 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 15 10:02:10 volumio volumio[1230]: info: Connecting to TidalConnect Oct 15 10:02:10 volumio volumio[1230]: info: CoreCommandRouter::servicePushState Oct 15 10:02:10 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:02:10 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:10 volumio volumio[1230]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:02:10 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:02:10 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:10 volumio volumio[1230]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current carrot_radio Received tidalconnect Oct 15 10:02:10 volumio volumio[1230]: info: CoreCommandRouter::servicePushState Oct 15 10:02:10 volumio volumio[1230]: info: CoreStateMachine::pushState Oct 15 10:02:10 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:10 volumio volumio[1230]: info: CoreCommandRouter::volumioPushState Oct 15 10:02:10 volumio volumio[1230]: info: CorePlayQueue::getTrack 1 Oct 15 10:02:10 volumio volumio[1230]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current carrot_radio Received tidalconnect Oct 15 10:02:10 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:10.737+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=75006 volume=38 Oct 15 10:02:10 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:10.738+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:02:10 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:10.740+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" state=STATUS_PAUSED positionMs=75006 volume=38 Oct 15 10:02:10 volumio volumio5-onboarding[1582]: time=2026-10-15T10:02:10.740+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.43:55500,00:00:00:00:00:00%01 @ 0x1c00f00" id=webcarrot/1 title="KBS HappyFM" Oct 15 10:02:10 volumio volumio[1230]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:02:10 volumio volumio[1230]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 15 10:02:10 volumio volumio[1230]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 10:02:10 volumio volumio[1230]: Error: ENOENT: no such file or directory, unlink '/tmp/AwnNWzLTTXOOQqxkPh9KUmddKGE51x6Y1mqvBLCyeAHPB7XbRkBiJN7MtqbcYjp2Q2hySh9n9qZUCknR5s4ekyH037IOeOnG1Rsf' Oct 15 10:02:10 volumio volumio[1230]: at Object.unlinkSync (node:fs:1899:3) Oct 15 10:02:10 volumio volumio[1230]: at ControllerTidalconnect.deleteCertificate (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:11265) Oct 15 10:02:10 volumio volumio[1230]: at TidalConnectClient. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:2774) Oct 15 10:02:10 volumio volumio[1230]: at TidalConnectClient.emit (node:events:514:28) Oct 15 10:02:10 volumio volumio[1230]: at TidalConnectClient.parseData (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:44713) Oct 15 10:02:10 volumio volumio[1230]: at /myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41683 Oct 15 10:02:10 volumio volumio[1230]: at Array.forEach () Oct 15 10:02:10 volumio volumio[1230]: at Socket. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41561) Oct 15 10:02:10 volumio volumio[1230]: at Socket.emit (node:events:514:28) Oct 15 10:02:10 volumio volumio[1230]: at addChunk (node:internal/streams/readable:343:12) Oct 15 10:02:10 volumio volumio[1230]: at readableAddChunk (node:internal/streams/readable:316:9) Oct 15 10:02:10 volumio volumio[1230]: at Readable.push (node:internal/streams/readable:253:10) Oct 15 10:02:10 volumio volumio[1230]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) { Oct 15 10:02:10 volumio volumio[1230]: errno: -2, Oct 15 10:02:10 volumio volumio[1230]: syscall: 'unlink', Oct 15 10:02:10 volumio volumio[1230]: code: 'ENOENT', Oct 15 10:02:10 volumio volumio[1230]: path: '/tmp/AwnNWzLTTXOOQqxkPh9KUmddKGE51x6Y1mqvBLCyeAHPB7XbRkBiJN7MtqbcYjp2Q2hySh9n9qZUCknR5s4ekyH037IOeOnG1Rsf' Oct 15 10:02:10 volumio volumio[1230]: } Oct 15 10:02:10 volumio volumio[1230]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 10:02:11 volumio sudo[3302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-15 10:01' Oct 15 10:02:11 volumio sudo[3302]: 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"