Oct 02 23:21:08 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:08 rivo vtcs[10559]: [feedThread:276] Exiting Oct 02 23:21:08 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:08 rivo vtcs[10559]: [2026-10-02 23:21:08.908] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=2, playstate_=1, player_state_=1 Oct 02 23:21:08 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:08 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:09 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:09 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:09 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:09 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:09 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:09 rivo vtcs[10559]: [open:50] Opening with sample rate: 44100, type: 0 Oct 02 23:21:09 rivo vtcs[10559]: [start:106] Entering Oct 02 23:21:09 rivo vtcs[10559]: [start:113] Reopening PCM device... Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:09 rivo vtcs[10559]: [start:115] PCM opened successfully. Oct 02 23:21:09 rivo vtcs[10559]: [start:120] Exiting Oct 02 23:21:09 rivo vtcs[10559]: [feedThread:223] Entering Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:09 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:10 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:10 rivo vtcs[10559]: [pause:147] Entering Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:10 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:10 rivo vtcs[10559]: [feedThread:276] Exiting Oct 02 23:21:10 rivo vtcs[10559]: [pause:161] Exiting Oct 02 23:21:10 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:10 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:10 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:11 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:11 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:11 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:11 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo vtcs[10559]: [2026-10-02 23:21:11.296] [tisoc] [warning] [PlaybackControllerImpl.cpp:213] Ignore play request because playback state is not STARTED. state_=2, playstate_=1, player_state_=0 Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:11 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:11 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:11 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:11 rivo vtcs[10559]: [open:50] Opening with sample rate: 48000, type: 3 Oct 02 23:21:11 rivo vtcs[10559]: [start:106] Entering Oct 02 23:21:11 rivo vtcs[10559]: [start:113] Reopening PCM device... Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:11 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:12 rivo vtcs[10559]: [start:115] PCM opened successfully. Oct 02 23:21:12 rivo vtcs[10559]: [start:120] Exiting Oct 02 23:21:12 rivo vtcs[10559]: [feedThread:223] Entering Oct 02 23:21:12 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:12 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:12 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:12 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:12 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:12 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:12 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:13 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:13 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:13 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:13 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:13 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:13 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:24 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:24 rivo vtcs[10559]: [feedThread:276] Exiting Oct 02 23:21:24 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:24 rivo vtcs[10559]: [2026-10-02 23:21:24.692] [tisoc] [warning] [PlaybackControllerImpl.cpp:213] Ignore play request because playback state is not STARTED. state_=2, playstate_=1, player_state_=0 Oct 02 23:21:24 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:24 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:24 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:24 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:24 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:25 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:25 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:25 rivo vtcs[10559]: [open:50] Opening with sample rate: 48000, type: 3 Oct 02 23:21:25 rivo vtcs[10559]: [start:106] Entering Oct 02 23:21:25 rivo vtcs[10559]: [start:113] Reopening PCM device... Oct 02 23:21:25 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:25 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:25 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:25 rivo vtcs[10559]: [start:115] PCM opened successfully. Oct 02 23:21:25 rivo vtcs[10559]: [start:120] Exiting Oct 02 23:21:25 rivo vtcs[10559]: [feedThread:223] Entering Oct 02 23:21:25 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:25 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:25 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:25 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:25 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:25 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:25 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:26 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:26 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:26 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:26 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:26 rivo volumio[3471]: info: Executing endpoint metavolumio Oct 02 23:21:26 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 02 23:21:31 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:31 rivo vtcs[10559]: [feedThread:276] Exiting Oct 02 23:21:31 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:31 rivo vtcs[10559]: [2026-10-02 23:21:31.557] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=2, playstate_=1, player_state_=1 Oct 02 23:21:31 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:31 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:31 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:31 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:31 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:32 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:32 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:32 rivo vtcs[10559]: [open:50] Opening with sample rate: 48000, type: 3 Oct 02 23:21:32 rivo vtcs[10559]: [start:106] Entering Oct 02 23:21:32 rivo vtcs[10559]: [start:113] Reopening PCM device... Oct 02 23:21:32 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:32 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:32 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:32 rivo vtcs[10559]: [start:115] PCM opened successfully. Oct 02 23:21:32 rivo vtcs[10559]: [start:120] Exiting Oct 02 23:21:32 rivo vtcs[10559]: [feedThread:223] Entering Oct 02 23:21:32 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:32 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:32 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:32 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:32 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:32 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:32 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:49 rivo vtcs[10559]: [feedThread:276] Exiting Oct 02 23:21:49 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:49 rivo vtcs[10559]: [2026-10-02 23:21:49.125] [tisoc] [warning] [PlaybackControllerImpl.cpp:220] Ignore play request because player state is already PLAYING. state_=2, playstate_=1, player_state_=1 Oct 02 23:21:49 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:49 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:49 rivo volumio[3471]: info: Pushing metadata Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo vtcs[10559]: [close:85] Entering Oct 02 23:21:49 rivo vtcs[10559]: [close:100] Exiting Oct 02 23:21:49 rivo vtcs[10559]: [open:50] Opening with sample rate: 48000, type: 3 Oct 02 23:21:49 rivo vtcs[10559]: [start:106] Entering Oct 02 23:21:49 rivo vtcs[10559]: [start:113] Reopening PCM device... Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo vtcs[10559]: [start:115] PCM opened successfully. Oct 02 23:21:49 rivo vtcs[10559]: [start:120] Exiting Oct 02 23:21:49 rivo vtcs[10559]: [feedThread:223] Entering Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:49 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:21:50 rivo volumio[3471]: info: CoreCommandRouter::servicePushState Oct 02 23:21:50 rivo volumio[3471]: info: CoreStateMachine::pushState Oct 02 23:21:50 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 23:21:50 rivo volumio[3471]: info: CoreCommandRouter::volumioPushState Oct 02 23:22:01 rivo volumio[3471]: verbose: New Socket.io Connection to 192.168.1.30 from 192.168.1.134 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260915.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 02 23:22:01 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:01 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:01 rivo volumio[3471]: info: Listing playlists Oct 02 23:22:01 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.764+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.134:54977 Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.792+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.134:54977 @ 0x2cbe810" latency=84.191563ms platform=PLATFORM_IOS version=6.260915.0 Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.794+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.134:54977 @ 0x2cbe810" latency=83.752482ms timeout=20s included=[] excluded=[] Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.794+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 02 23:22:03 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:03 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.806+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" name=Rivo Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.811+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" language=it Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.818+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" timezone=Europe/Rome Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.820+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" available=true connected=false macAddress= ip4Address= ip6Address= Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.826+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" available=true connected=true macAddress=70:4a:0e:ab:c0:4c ip4Address=192.168.1.30/24 ip6Address= ssid="Scheda Wi Fi 5 GHZ" Oct 02 23:22:03 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:03.827+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" setupComplete=true Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 02 23:22:03 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4, ...) Oct 02 23:22:03 rivo volumio[3471]: amixer -c 5 info | grep "ADI-2 DAC (51090331)" Oct 02 23:22:03 rivo volumio[3471]: Card sysdefault:5 'DAC51090331'/'RME ADI-2 DAC (51090331) at usb-xhci-hcd.0.auto-1.4.1, high speed' Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 23:22:03 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:03 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:03 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:04 rivo volumio[3471]: amixer -c 5 info | grep "ADI-2 DAC (51090331)" Oct 02 23:22:04 rivo volumio[3471]: Card sysdefault:5 'DAC51090331'/'RME ADI-2 DAC (51090331) at usb-xhci-hcd.0.auto-1.4.1, high speed' Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.076+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" selectedOutputId=5 Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:04 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:04 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:04 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.100+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" currentVersion=4.208 latestVersion=4.208 Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.102+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" status=UPDATE_STATUS_NONE progress=0 Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.103+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" userId=mXmwYvmKk0YtOIWnW2XhDE30pLh2 Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.104+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" providers=9 Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.105+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" plugins=27 Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.114+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" state=STATUS_PLAYING positionMs=13900 volume=100 Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.115+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.134:54977 @ 0x2cbe810" id= title=April Oct 02 23:22:04 rivo volumio[3471]: verbose: New Socket.io Connection to 192.168.1.30:3000 from 192.168.1.134 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.129+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 02 23:22:04 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.321+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=http://pushupdates.volumio.org duration=182.673636ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.371+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=240.639428ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.452+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://www.googleapis.com duration=315.185409ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.489+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://securetoken.googleapis.com duration=351.395821ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.548+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://google.com duration=418.679955ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.555+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=422.508607ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.623+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://functions.volumio.cloud duration=487.51154ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.625+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://functions.volumio.cloud duration=489.841866ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.649+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=512.979325ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.725+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=593.554743ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.827+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=https://database.volumio.cloud duration=690.056189ms Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.960+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.941976ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.960+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=http://cddb.volumio.org duration=826.132282ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.971+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s Oct 02 23:22:04 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:04.984+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=12.704538ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.012+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=39.790232ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.016+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=44.002884ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.057+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://google.com duration=84.343863ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.072+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=http://pushupdates.volumio.org duration=99.838599ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.085+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://www.googleapis.com duration=112.695511ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.123+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://securetoken.googleapis.com duration=151.126373ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.123+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://functions.volumio.cloud duration=151.92737ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.126+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://functions.volumio.cloud duration=154.045528ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.127+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=75.115105ms timeout=10s endpoint=http://plugins.volumio.org duration=990.769273ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.244+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=http://cddb.volumio.org duration=272.056103ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 02 23:22:05 rivo sudo[10973]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 02 23:22:05 rivo sudo[10974]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 02 23:22:05 rivo sudo[10973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 23:22:05 rivo sudo[10974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.266+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=293.270111ms Oct 02 23:22:05 rivo sudo[10974]: pam_unix(sudo:session): session closed for user root Oct 02 23:22:05 rivo sudo[10973]: pam_unix(sudo:session): session closed for user root Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.279+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=https://database.volumio.cloud duration=306.369897ms Oct 02 23:22:05 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:05.312+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.134:54977 @ 0x2cbe810" latency=76.009498ms timeout=10s endpoint=http://plugins.volumio.org duration=339.805193ms Oct 02 23:22:05 rivo volumio[3471]: verbose: New Socket.io Connection to 192.168.1.30 from 192.168.1.134 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260915.0 Engine version: 3 Transport: polling Total Clients: 8 Oct 02 23:22:05 rivo sudo[10980]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 02 23:22:05 rivo sudo[10982]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 02 23:22:05 rivo sudo[10980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 23:22:05 rivo sudo[10982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 23:22:05 rivo sudo[10982]: pam_unix(sudo:session): session closed for user root Oct 02 23:22:05 rivo sudo[10980]: pam_unix(sudo:session): session closed for user root Oct 02 23:22:05 rivo volumio[3471]: verbose: New Socket.io Connection to 192.168.1.30 from 192.168.1.134 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260915.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 02 23:22:05 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:05 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:05 rivo volumio[3471]: info: Listing playlists Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 23:22:05 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 23:22:07 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 02 23:22:07 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 23:22:07 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:07 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:07 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:07 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:07 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:07 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:07 rivo volumio5-onboarding[4561]: time=2026-10-02T23:22:07.663+02:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Oct 02 23:22:07 rivo volumio[3471]: info: CoreCommandRouter::volumioGetQueue Oct 02 23:22:07 rivo volumio[3471]: info: CoreStateMachine::getQueue Oct 02 23:22:07 rivo volumio[3471]: info: CorePlayQueue::getQueue Oct 02 23:22:08 rivo dbus-daemon[2933]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.22" (uid=0 pid=4561 comm="/usr/bin/volumio5-onboarding" label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.6" (uid=0 pid=3306 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b" label="kernel") Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0001, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0001/char0002, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0001/char0004, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0006, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0006/char0007, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0006/char0007/desc0009, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service000a, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service000a/char000b, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service000a/char000d, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service000f, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service000f/char0010, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service000f/char0010/desc0012, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service000f/char0010/desc0013, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0014, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0014/char0015, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0014/char0015/desc0017, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0014/char0015/desc0018, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0019, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0019/char001a, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0019/char001a/desc001c, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service001d, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service001d/char001e, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service001d/char001e/desc0020, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service001d/char0021, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0023, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0023/char0024, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0023/char0024/desc0026, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0023/char0027, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0023/char0027/desc0029, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0023/char002a, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service0023/char002a/desc002c, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char002e, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char002e/desc0030, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char002e/desc0031, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char0032, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char0032/desc0034, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char0032/desc0035, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char0036, ...) Oct 02 23:22:08 rivo bluealsa[3307]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_44_E9_97_67_78_C4/service002d/char0036/desc0038, ...) Oct 02 23:22:08 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 23:22:08 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:08 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:08 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:08 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:08 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:08 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:15 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 02 23:22:18 rivo volumio[3471]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 23:22:18 rivo volumio[3471]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 23:22:18 rivo volumio[3471]: info: Retrieving Cloud Streaming UI Oct 02 23:22:18 rivo volumio[3471]: info: Getting Tidal Cloud Configuration Oct 02 23:22:18 rivo volumio[3471]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 23:22:18 rivo volumio[3471]: info: Getting Qobuz Cloud Configuration Oct 02 23:22:18 rivo volumio[3471]: info: Asking plugin for UI Config Oct 02 23:22:18 rivo volumio[3471]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 23:22:19 rivo volumio[3471]: info: Getting Spotify Cloud Configuration Oct 02 23:22:19 rivo volumio[3471]: info: Asking plugin for UI Config Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 23:22:19 rivo volumio[3471]: info: Saving Spotify Acccount Oct 02 23:22:19 rivo volumio[3471]: info: Got it Oct 02 23:22:19 rivo volumio[3471]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 02 23:22:19 rivo volumio[3471]: info: Got Tidal Cloud Configuration Oct 02 23:22:19 rivo volumio[3471]: info: Got it Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 23:22:19 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 02 23:22:23 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 23:22:23 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 23:22:24 rivo volumio[3471]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 02 23:22:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 02 23:22:24 rivo volumio[3471]: info: Received Get System Version Oct 02 23:22:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 23:22:24 rivo volumio[3471]: info: Received Get System Info Oct 02 23:22:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 23:22:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 23:22:24 rivo volumio[3471]: info: Discovery: Getting this device information Oct 02 23:22:24 rivo volumio[3471]: info: CoreCommandRouter::volumioGetState Oct 02 23:22:24 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 23:22:27 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 23:22:31 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 23:22:33 rivo volumio[3471]: info: Disabling MyMusic plugin upnp Oct 02 23:22:33 rivo sudo[11043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Oct 02 23:22:33 rivo sudo[11043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 23:22:33 rivo systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Oct 02 23:22:35 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 23:22:37 rivo volumio[3471]: info: Enabling MyMusic plugin upnp Oct 02 23:22:37 rivo volumio[3471]: info: Enabling plugin upnp Oct 02 23:22:37 rivo volumio[3471]: info: Loading plugin "upnp"... Oct 02 23:22:37 rivo volumio[3471]: info: [1790976157022] Starting Upmpd Daemon Oct 02 23:22:37 rivo volumio[3471]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 02 23:22:37 rivo volumio[3471]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 23:22:37 rivo volumio[3471]: Error: listen EADDRINUSE: address already in use :::6599 Oct 02 23:22:37 rivo volumio[3471]: at Server.setupListenHandle [as _listen2] (node:net:1872:16) Oct 02 23:22:37 rivo volumio[3471]: at listenInCluster (node:net:1920:12) Oct 02 23:22:37 rivo volumio[3471]: at Server.listen (node:net:2008:7) Oct 02 23:22:37 rivo volumio[3471]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Oct 02 23:22:37 rivo volumio[3471]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Oct 02 23:22:37 rivo volumio[3471]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Oct 02 23:22:37 rivo volumio[3471]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 02 23:22:37 rivo volumio[3471]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Oct 02 23:22:37 rivo volumio[3471]: code: 'EADDRINUSE', Oct 02 23:22:37 rivo volumio[3471]: errno: -98, Oct 02 23:22:37 rivo volumio[3471]: syscall: 'listen', Oct 02 23:22:37 rivo volumio[3471]: address: '::', Oct 02 23:22:37 rivo volumio[3471]: port: 6599 Oct 02 23:22:37 rivo volumio[3471]: } Oct 02 23:22:37 rivo volumio[3471]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 23:22:37 rivo sudo[11055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-02 23:21' Oct 02 23:22:37 rivo sudo[11055]: 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="8ed05bf20f96eb8557ed5652c420f84f39d66325" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0a52c1fb90959ba1872a2fb0225e56fe615b19ac" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Sep 16 16:27:36 UTC 2026" VOLUMIO_VERSION="4.208" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="be0c94671215c2b1bf2440825a1e4211"