Feb 12 03:07:17 volumio vtcs[9106]: [close:85] Entering Feb 12 03:07:17 volumio vtcs[9106]: [feedThread:276] Exiting Feb 12 03:07:17 volumio vtcs[9106]: [close:100] Exiting Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:17 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:17 volumio go-librespot[6910]: time="2026-02-12T03:07:17Z" level=trace msg="sent dealer ping" Feb 12 03:07:17 volumio go-librespot[6910]: time="2026-02-12T03:07:17Z" level=trace msg="received dealer pong" Feb 12 03:07:17 volumio vtcs[9106]: [2026-02-12 03:07:17.866] [tisoc] [warning] [PlaybackControllerImpl.cpp:213] Ignore play request because playback state is not STARTED. state_=2, playstate_=1, player_state_=0 Feb 12 03:07:17 volumio volumio[1293]: info: Pushing metadata Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:17 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:17 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:17 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:17 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:17 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:17 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:18 volumio vtcs[9106]: [close:85] Entering Feb 12 03:07:18 volumio vtcs[9106]: [close:100] Exiting Feb 12 03:07:18 volumio volumio[1293]: info: Pushing metadata Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:18 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:18 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:18 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:18 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:18 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:18 volumio vtcs[9106]: [close:85] Entering Feb 12 03:07:18 volumio vtcs[9106]: [close:100] Exiting Feb 12 03:07:18 volumio vtcs[9106]: [open:50] Opening with sample rate: 44100, type: 3 Feb 12 03:07:18 volumio vtcs[9106]: [start:106] Entering Feb 12 03:07:18 volumio vtcs[9106]: [start:113] Reopening PCM device... Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:18 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:18 volumio vtcs[9106]: [start:115] PCM opened successfully. Feb 12 03:07:18 volumio vtcs[9106]: [start:120] Exiting Feb 12 03:07:18 volumio vtcs[9106]: [feedThread:223] Entering Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:18 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:18 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:18 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:19 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:19 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:19 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:19 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Feb 12 03:07:19 volumio volumio[1293]: info: Volume: {"mute":false} Feb 12 03:07:19 volumio volumio[1293]: info: VolumeController::SetAlsaVolume51 Feb 12 03:07:19 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:19 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:19 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:19 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Feb 12 03:07:19 volumio volumio[1293]: SPOTIFY: SPOTIFY VOLUME 50 Feb 12 03:07:19 volumio volumio[1293]: SPOTIFY: VOLUMIO VOLUME 51 Feb 12 03:07:19 volumio volumio[1293]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 12 03:07:19 volumio volumio[1293]: info: Executing endpoint metavolumio Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 03:07:19 volumio volumio[1293]: info: Executing endpoint metavolumio Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 03:07:19 volumio volumio[1293]: info: Executing endpoint metavolumio Feb 12 03:07:19 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 03:07:20 volumio volumio[1293]: info: Volume: {"mute":false} Feb 12 03:07:20 volumio volumio[1293]: info: VolumeController::SetAlsaVolume52 Feb 12 03:07:20 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:20 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:20 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:20 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:20 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:20 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:20 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:20 volumio volumio[1293]: SPOTIFY: SPOTIFY VOLUME 50 Feb 12 03:07:20 volumio volumio[1293]: SPOTIFY: VOLUMIO VOLUME 52 Feb 12 03:07:20 volumio volumio[1293]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 12 03:07:20 volumio volumio[1293]: info: Setting Spotify Volume from Volumio: 52 Feb 12 03:07:22 volumio volumio[1293]: SPOTIFY: SETTING SPOTIFY VOLUME 52 Feb 12 03:07:22 volumio volumio[1293]: info: Sending Spotify command with payload to local API: /player/volume Feb 12 03:07:22 volumio go-librespot[6910]: time="2026-02-12T03:07:22Z" level=debug msg="update volume requested to 34078/65535" Feb 12 03:07:22 volumio go-librespot[6910]: time="2026-02-12T03:07:22Z" level=debug msg="put connect state because VOLUME_CHANGED" Feb 12 03:07:22 volumio go-librespot[6910]: time="2026-02-12T03:07:22Z" level=trace msg="emitting websocket event: volume" Feb 12 03:07:22 volumio volumio[1293]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Feb 12 03:07:22 volumio volumio[1293]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Feb 12 03:07:22 volumio volumio[1293]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Feb 12 03:07:22 volumio volumio[1293]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Feb 12 03:07:22 volumio volumio[1293]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Feb 12 03:07:22 volumio volumio[1293]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Feb 12 03:07:24 volumio go-librespot[6910]: time="2026-02-12T03:07:24Z" level=trace msg="received accesspoint ping" Feb 12 03:07:24 volumio go-librespot[6910]: time="2026-02-12T03:07:24Z" level=trace msg="received accesspoint pong ack" Feb 12 03:07:37 volumio vtcs[9106]: [close:85] Entering Feb 12 03:07:37 volumio vtcs[9106]: [feedThread:276] Exiting Feb 12 03:07:37 volumio vtcs[9106]: [close:100] Exiting Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:37 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:37 volumio vtcs[9106]: [2026-02-12 03:07:37.902] [tisoc] [warning] [PlaybackControllerImpl.cpp:213] Ignore play request because playback state is not STARTED. state_=2, playstate_=1, player_state_=0 Feb 12 03:07:37 volumio volumio[1293]: info: Pushing metadata Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:37 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:37 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:37 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:37 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:37 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:38 volumio vtcs[9106]: [close:85] Entering Feb 12 03:07:38 volumio vtcs[9106]: [close:100] Exiting Feb 12 03:07:38 volumio volumio[1293]: info: Pushing metadata Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:38 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:38 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:38 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:38 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:38 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:38 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:39 volumio vtcs[9106]: [close:85] Entering Feb 12 03:07:39 volumio vtcs[9106]: [close:100] Exiting Feb 12 03:07:39 volumio vtcs[9106]: [open:50] Opening with sample rate: 44100, type: 0 Feb 12 03:07:39 volumio vtcs[9106]: [start:106] Entering Feb 12 03:07:39 volumio vtcs[9106]: [start:113] Reopening PCM device... Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:39 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:39 volumio vtcs[9106]: [start:115] PCM opened successfully. Feb 12 03:07:39 volumio vtcs[9106]: [start:120] Exiting Feb 12 03:07:39 volumio vtcs[9106]: [feedThread:223] Entering Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:39 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:39 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:07:39 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:07:39 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:07:39 volumio volumio[1293]: info: Executing endpoint metavolumio Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 03:07:39 volumio volumio[1293]: info: Executing endpoint metavolumio Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 03:07:39 volumio volumio[1293]: info: Executing endpoint metavolumio Feb 12 03:07:39 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 03:07:47 volumio go-librespot[6910]: time="2026-02-12T03:07:47Z" level=trace msg="sent dealer ping" Feb 12 03:07:48 volumio go-librespot[6910]: time="2026-02-12T03:07:48Z" level=trace msg="received dealer pong" Feb 12 03:08:09 volumio vtcs[9106]: [pause:147] Entering Feb 12 03:08:09 volumio volumio[1293]: info: CoreCommandRouter::servicePushState Feb 12 03:08:09 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:08:09 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:08:09 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:08:09 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:08:09 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:08:09 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:09 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:08:09 volumio vtcs[9106]: [feedThread:276] Exiting Feb 12 03:08:09 volumio vtcs[9106]: [pause:161] Exiting Feb 12 03:08:17 volumio go-librespot[6910]: time="2026-02-12T03:08:17Z" level=trace msg="sent dealer ping" Feb 12 03:08:17 volumio go-librespot[6910]: time="2026-02-12T03:08:17Z" level=trace msg="received dealer pong" Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.836Z level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.101:45340 Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.849Z level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.101:45340 @ 0xc000111590" latency=-809.529697ms platform=PLATFORM_ANDROID version=5.260120.0 Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.850Z level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.101:45340 @ 0xc000111590" latency=-809.208821ms timeout=10s Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.850Z level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" Feb 12 03:08:33 volumio volumio[1293]: info: Received Get System Info Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:33 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.852Z level=INFO msg="emitting device name changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" name=Volumio Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.852Z level=INFO msg="emitting device language changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" language=en Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.853Z level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" timezone=UTC Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.853Z level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" available=true connected=true macAddress=a0:2b:b8:46:96:c3 ip4Address=192.168.1.103/24 ip6Address= Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.853Z level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.853Z level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" setupComplete=true Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 12 03:08:33 volumio volumio[1293]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 1 -D 0 Feb 12 03:08:33 volumio volumio[1293]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 12 03:08:33 volumio volumio[1293]: {"cmd":"/usr/local/bin/alsacap -C 1 -D 0","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 1 -D 0\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 12 03:08:33 volumio volumio[1293]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 8 Feb 12 03:08:33 volumio volumio[1293]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 12 03:08:33 volumio volumio[1293]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 8","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 8\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 12 03:08:33 volumio volumio[1293]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 7 Feb 12 03:08:33 volumio volumio[1293]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 12 03:08:33 volumio volumio[1293]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 7","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 7\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 12 03:08:33 volumio volumio[1293]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 3 Feb 12 03:08:33 volumio volumio[1293]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 12 03:08:33 volumio volumio[1293]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 3\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 12 03:08:33 volumio volumio[1293]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Feb 12 03:08:33 volumio volumio[1293]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 12 03:08:33 volumio volumio[1293]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 12 03:08:33 volumio volumio[1293]: amixer -c 5 info | grep "FIIO KA17" Feb 12 03:08:33 volumio volumio[1293]: Card sysdefault:5 'KA17'/'GuangZhou FIIO Electronics Co.,Ltd FIIO KA17 at usb-0000:00:14.0-2, high speed' Feb 12 03:08:33 volumio volumio[1293]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Feb 12 03:08:33 volumio volumio[1293]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 12 03:08:33 volumio volumio[1293]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 12 03:08:33 volumio volumio[1293]: amixer -c 5 info | grep "FIIO KA17" Feb 12 03:08:33 volumio volumio[1293]: Card sysdefault:5 'KA17'/'GuangZhou FIIO Electronics Co.,Ltd FIIO KA17 at usb-0000:00:14.0-2, high speed' Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.904Z level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" selectedOutputId=5 Feb 12 03:08:33 volumio volumio[1293]: info: Received Get System Info Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:33 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.982Z level=INFO msg="emitting software info changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" currentVersion=4.096 latestVersion=4.096 Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.982Z level=INFO msg="emitting software update progress event" component=server peer="192.168.1.101:45340 @ 0xc000111590" status=UPDATE_STATUS_NONE progress=0 Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.982Z level=INFO msg="emitting user changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" userId= Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.982Z level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" providers=3 Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.982Z level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" plugins=44 Feb 12 03:08:33 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.983Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" state=STATUS_PAUSED positionMs=30511 volume=52 Feb 12 03:08:33 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:33.983Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" id= title=Reflections Feb 12 03:08:34 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:34 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:34 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:34 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:34 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:34 volumio volumio[1293]: verbose: New Socket.io Connection to 192.168.1.103:3000 from 192.168.1.101 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Feb 12 03:08:34 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 12 03:08:34 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 12 03:08:35 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:35.499Z level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.101:45340 @ 0xc000111590" latency=-805.041856ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Feb 12 03:08:36 volumio sudo[16607]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 03:08:36 volumio sudo[16607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 03:08:36 volumio sudo[16607]: pam_unix(sudo:session): session closed for user root Feb 12 03:08:36 volumio sudo[16609]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 03:08:36 volumio sudo[16609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 03:08:36 volumio sudo[16609]: pam_unix(sudo:session): session closed for user root Feb 12 03:08:36 volumio volumio[1293]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.101 UA: Mozilla/5.0 (Linux; Android 15; A063 Build/AQ3A.240929.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Feb 12 03:08:36 volumio sudo[16613]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 03:08:36 volumio sudo[16613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 03:08:36 volumio sudo[16615]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 03:08:36 volumio sudo[16613]: pam_unix(sudo:session): session closed for user root Feb 12 03:08:36 volumio sudo[16615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 03:08:36 volumio sudo[16615]: pam_unix(sudo:session): session closed for user root Feb 12 03:08:36 volumio volumio[1293]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.101 UA: Mozilla/5.0 (Linux; Android 15; A063 Build/AQ3A.240929.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Feb 12 03:08:36 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetVisibleSources Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 12 03:08:37 volumio volumio[1293]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Feb 12 03:08:37 volumio volumio[1293]: info: Received Get System Info Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:37 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:37 volumio volumio[1293]: info: Listing playlists Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 12 03:08:37 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 12 03:08:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 12 03:08:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 03:08:38 volumio volumio[1293]: info: Received Get System Info Feb 12 03:08:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:38 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:38 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:38 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 03:08:41 volumio volumio[1293]: info: Received Get System Info Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:41 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 12 03:08:41 volumio volumio[1293]: info: Retrieving Cloud Streaming UI Feb 12 03:08:41 volumio volumio[1293]: info: Getting Tidal Cloud Configuration Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 12 03:08:41 volumio volumio[1293]: info: Getting Qobuz Cloud Configuration Feb 12 03:08:41 volumio volumio[1293]: info: Asking plugin for UI Config Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 12 03:08:41 volumio volumio[1293]: info: Getting Spotify Cloud Configuration Feb 12 03:08:41 volumio volumio[1293]: info: Asking plugin for UI Config Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 12 03:08:41 volumio volumio[1293]: info: Saving Spotify Acccount Feb 12 03:08:41 volumio volumio[1293]: info: Got it Feb 12 03:08:41 volumio volumio[1293]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 12 03:08:41 volumio volumio[1293]: info: Got Tidal Cloud Configuration Feb 12 03:08:41 volumio volumio[1293]: info: Got it Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::volumioGetBrowseSources Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::volumioGetBrowseSources Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::volumioGetBrowseSources Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 12 03:08:41 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 12 03:08:42 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 03:08:42 volumio volumio[1293]: info: Received Get System Info Feb 12 03:08:42 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:42 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:42 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:42 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:42 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:43 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 03:08:43 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 03:08:43 volumio volumio[1293]: info: Received Get System Info Feb 12 03:08:43 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 03:08:43 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 03:08:43 volumio volumio[1293]: info: Discovery: Getting this device information Feb 12 03:08:43 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:43 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 03:08:45 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 12 03:08:46 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 12 03:08:47 volumio volumio[1293]: info: Disabling MyMusic plugin bluetooth Feb 12 03:08:47 volumio volumio[1293]: info: [MyVolumio PluginManager] Disabling and stopping plugin audio_interface bluetooth Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: [FUNC] onStop Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: Bluetooth audio output stopped Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: [FUNC] stopBTStack Feb 12 03:08:47 volumio sudo[16648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumiobt.service Feb 12 03:08:47 volumio sudo[16648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 03:08:47 volumio sudo[16648]: pam_unix(sudo:session): session closed for user root Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: volumiobt.service stopped successfully Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: volumiobt.service stopped Feb 12 03:08:47 volumio volumio[1293]: verbose: UNSET VOLATILE: Service: tidalconnect Feb 12 03:08:47 volumio volumio[1293]: info: unSetVolatile called Feb 12 03:08:47 volumio volumio[1293]: info: Relinquishing Volumio State to another service Feb 12 03:08:47 volumio volumio[1293]: info: CoreStateMachine::resetVolumioState Feb 12 03:08:47 volumio volumio[1293]: info: CoreStateMachine::getcurrentVolume Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 03:08:47 volumio vtcs[9106]: [close:85] Entering Feb 12 03:08:47 volumio vtcs[9106]: [close:100] Exiting Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: Volumio state reset after Bluetooth stop Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::volumioStop Feb 12 03:08:47 volumio volumio[1293]: info: CoreStateMachine::stop Feb 12 03:08:47 volumio volumio[1293]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 03:08:47 volumio vtcs[9106]: [2026-02-12 03:08:47] [info] asio async_shutdown error: asio.misc:2 (End of file) Feb 12 03:08:47 volumio volumio[1293]: info: PlaybackInactive Feb 12 03:08:47 volumio volumio[1293]: info: Device Session is_active: true Feb 12 03:08:47 volumio volumio[1293]: info: DeviceInactive Feb 12 03:08:47 volumio volumio[1293]: info: Relinquishing Volumio State Feb 12 03:08:47 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:08:47 volumio volumio[1293]: info: CorePlayQueue::getTrack 0 Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:08:47 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:08:47 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:47 volumio volumio[1293]: info: CorePlayQueue::getTrack 0 Feb 12 03:08:47 volumio volumio[1293]: info: CoreStateMachine::updateTrackBlock Feb 12 03:08:47 volumio volumio[1293]: info: CorePlayQueue::getTrackBlock Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 03:08:47 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:47.523Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" state=STATUS_STOPPED positionMs=0 volume=52 Feb 12 03:08:47 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:47.523Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" id= title= Feb 12 03:08:47 volumio go-librespot[6910]: time="2026-02-12T03:08:47Z" level=trace msg="sent dealer ping" Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: SPOTIFY VOLUME 52 Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: VOLUMIO VOLUME 52 Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 12 03:08:47 volumio volumio[1293]: ------------------------------------ BT MESSAGE: Failed to power off adapter: Feb 12 03:08:47 volumio volumio[1293]: info: Disabling plugin bluetooth Feb 12 03:08:47 volumio volumio[1293]: info: CoreStateMachine::pushState Feb 12 03:08:47 volumio volumio[1293]: info: CorePlayQueue::getTrack 0 Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::volumioPushState Feb 12 03:08:47 volumio volumio[1293]: info: MRS: Pushing multiroomSync output update for this device Feb 12 03:08:47 volumio volumio[1293]: info: MRS: Pushing multiroomSync output Feb 12 03:08:47 volumio volumio[1293]: info: CoreCommandRouter::volumioGetState Feb 12 03:08:47 volumio volumio[1293]: info: CorePlayQueue::getTrack 0 Feb 12 03:08:47 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:47.545Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" state=STATUS_STOPPED positionMs=0 volume=52 Feb 12 03:08:47 volumio volumio5-onboarding[2021]: time=2026-02-12T03:08:47.545Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.101:45340 @ 0xc000111590" id= title= Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: SPOTIFY VOLUME 52 Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: VOLUMIO VOLUME 52 Feb 12 03:08:47 volumio volumio[1293]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 12 03:08:47 volumio go-librespot[6910]: time="2026-02-12T03:08:47Z" level=trace msg="received dealer pong" Feb 12 03:08:48 volumio volumio[1293]: info: Disabling MyMusic plugin upnp Feb 12 03:08:48 volumio sudo[16691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Feb 12 03:08:48 volumio sudo[16691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 03:08:48 volumio systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Feb 12 03:08:49 volumio volumio[1293]: info: Enabling MyMusic plugin upnp Feb 12 03:08:49 volumio volumio[1293]: info: Enabling plugin upnp Feb 12 03:08:49 volumio volumio[1293]: info: Loading plugin "upnp"... Feb 12 03:08:49 volumio volumio[1293]: info: [1770865729466] Starting Upmpd Daemon Feb 12 03:08:49 volumio volumio[1293]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 03:08:49 volumio volumio[1293]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 03:08:49 volumio volumio[1293]: Error: listen EADDRINUSE: address already in use :::6599 Feb 12 03:08:49 volumio volumio[1293]: at Server.setupListenHandle [as _listen2] (node:net:1872:16) Feb 12 03:08:49 volumio volumio[1293]: at listenInCluster (node:net:1920:12) Feb 12 03:08:49 volumio volumio[1293]: at Server.listen (node:net:2008:7) Feb 12 03:08:49 volumio volumio[1293]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Feb 12 03:08:49 volumio volumio[1293]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Feb 12 03:08:49 volumio volumio[1293]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Feb 12 03:08:49 volumio volumio[1293]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 12 03:08:49 volumio volumio[1293]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Feb 12 03:08:49 volumio volumio[1293]: code: 'EADDRINUSE', Feb 12 03:08:49 volumio volumio[1293]: errno: -98, Feb 12 03:08:49 volumio volumio[1293]: syscall: 'listen', Feb 12 03:08:49 volumio volumio[1293]: address: '::', Feb 12 03:08:49 volumio volumio[1293]: port: 6599 Feb 12 03:08:49 volumio volumio[1293]: } Feb 12 03:08:49 volumio volumio[1293]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 03:08:49 volumio sudo[16708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 03:07' Feb 12 03:08:49 volumio sudo[16708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:31:57 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6759e875c98b942866984e844891d6c1"