-- Logs begin at Wed 2025-04-23 23:28:07 CEST, end at Wed 2025-04-23 23:55:09 CEST. -- Apr 23 23:54:04 rivoplus volumio[13845]: info: Executing endpoint metavolumio Apr 23 23:54:04 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 23 23:54:04 rivoplus volumio[13845]: info: Executing endpoint metavolumio Apr 23 23:54:04 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 23 23:54:05 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 23:54:05 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 23:54:05 rivoplus volumio[13845]: info: Discovery: Getting this device information Apr 23 23:54:05 rivoplus volumio[13845]: info: CoreCommandRouter::volumioGetState Apr 23 23:54:05 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 23:54:10 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 23 23:54:10 rivoplus volumio[13845]: info: handleBrowseUri took 316 milliseconds Apr 23 23:54:10 rivoplus volumio[13845]: info: Preload queue cleared Apr 23 23:54:10 rivoplus volumio[13845]: info: Preload queue cleared Apr 23 23:54:12 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 23 23:54:13 rivoplus volumio[13845]: info: handleBrowseUri took 432 milliseconds Apr 23 23:54:13 rivoplus volumio[13845]: info: Preload queue cleared Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::volumioPause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::stPlaybackTimer Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::servicePause Apr 23 23:54:32 rivoplus volumio[13845]: info: CorePlayQueue::getTrack 4 Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::servicePause Apr 23 23:54:32 rivoplus volumio[13845]: info: [1745445272493] ControllerQobuz::pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 23 23:54:32 rivoplus volumio[13845]: info: ControllerMpd::pause Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::sendMpdCommand pause Apr 23 23:54:32 rivoplus volumio[13845]: info: Apr 23 23:54:32 rivoplus volumio[13845]: ---------------------------- MPD announces state update: player Apr 23 23:54:32 rivoplus volumio[13845]: info: sendMpdCommand pause took 6 milliseconds Apr 23 23:54:32 rivoplus volumio[13845]: info: ControllerMpd::getState Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::sendMpdCommand status Apr 23 23:54:32 rivoplus volumio[13845]: info: Apr 23 23:54:32 rivoplus volumio[13845]: ---------------------------- MPD announces state update: player Apr 23 23:54:32 rivoplus volumio[13845]: info: ControllerMpd::getState Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::sendMpdCommand status Apr 23 23:54:32 rivoplus volumio[13845]: info: Apr 23 23:54:32 rivoplus volumio[13845]: ---------------------------- MPD announces state update: player Apr 23 23:54:32 rivoplus volumio[13845]: info: ControllerMpd::getState Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::sendMpdCommand status Apr 23 23:54:32 rivoplus volumio[13845]: info: sendMpdCommand status took 7 milliseconds Apr 23 23:54:32 rivoplus volumio[13845]: info: sendMpdCommand status took 6 milliseconds Apr 23 23:54:32 rivoplus volumio[13845]: info: sendMpdCommand status took 6 milliseconds Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::parseState Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::parseState Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::parseState Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 23 23:54:32 rivoplus volumio[13845]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 23 23:54:32 rivoplus volumio[13845]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 23 23:54:32 rivoplus volumio[13845]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::parseTrackInfo Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::parseTrackInfo Apr 23 23:54:32 rivoplus volumio[13845]: verbose: ControllerMpd::parseTrackInfo Apr 23 23:54:32 rivoplus volumio[13845]: info: ControllerMpd::pushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::servicePushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CorePlayQueue::getTrack 4 Apr 23 23:54:32 rivoplus volumio[13845]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":89826,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"885 Kbps","isStreaming":false,"title":"300009168","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/300009168","trackType":"qobuz"} Apr 23 23:54:32 rivoplus volumio[13845]: verbose: CURRENT POSITION 4 Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::syncState stateService pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::syncState currentStatus pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::pushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::volumioPushState Apr 23 23:54:32 rivoplus volumio[13845]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:54:32 rivoplus volumio[13845]: info: MRS: Pushing multiroomSync output Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::stPlaybackTimer Apr 23 23:54:32 rivoplus volumio[13845]: info: ControllerMpd::pushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::servicePushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CorePlayQueue::getTrack 4 Apr 23 23:54:32 rivoplus volumio[13845]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":89826,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"885 Kbps","isStreaming":false,"title":"300009168","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/300009168","trackType":"qobuz"} Apr 23 23:54:32 rivoplus volumio[13845]: verbose: CURRENT POSITION 4 Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::syncState stateService pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::syncState currentStatus pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::pushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::volumioPushState Apr 23 23:54:32 rivoplus volumio[13845]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:54:32 rivoplus volumio[13845]: info: MRS: Pushing multiroomSync output Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::stPlaybackTimer Apr 23 23:54:32 rivoplus volumio[13845]: info: ControllerMpd::pushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::servicePushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CorePlayQueue::getTrack 4 Apr 23 23:54:32 rivoplus volumio[13845]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":89826,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"885 Kbps","isStreaming":false,"title":"300009168","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/300009168","trackType":"qobuz"} Apr 23 23:54:32 rivoplus volumio[13845]: verbose: CURRENT POSITION 4 Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::syncState stateService pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::syncState currentStatus pause Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::pushState Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreCommandRouter::volumioPushState Apr 23 23:54:32 rivoplus volumio[13845]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:54:32 rivoplus volumio[13845]: info: MRS: Pushing multiroomSync output Apr 23 23:54:32 rivoplus volumio[13845]: info: CoreStateMachine::stPlaybackTimer Apr 23 23:54:32 rivoplus volumio[13845]: info: ------------------------------ 54ms Apr 23 23:54:32 rivoplus volumio[13845]: info: ------------------------------ 53ms Apr 23 23:54:32 rivoplus volumio[13845]: info: ------------------------------ 52ms Apr 23 23:54:32 rivoplus volumio[13845]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 23 23:54:32 rivoplus volumio[13845]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 23 23:54:32 rivoplus volumio[13845]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 23 23:54:32 rivoplus volumio[13845]: info: MCU Signalled Playback Inactive Apr 23 23:54:35 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 23:54:35 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 23:54:35 rivoplus volumio[13845]: info: Discovery: Getting this device information Apr 23 23:54:35 rivoplus volumio[13845]: info: CoreCommandRouter::volumioGetState Apr 23 23:54:35 rivoplus volumio[13845]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 23:54:54 rivoplus volumio[13845]: info: MRS: Found cast device: MIBOX4-7ba2431bba219742ef4d4f31422cab9f Apr 23 23:55:08 rivoplus volumio[13845]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 23:55:08 rivoplus volumio[13845]: Error: connect ETIMEDOUT 151.101.134.79:443 Apr 23 23:55:08 rivoplus volumio[13845]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Apr 23 23:55:08 rivoplus volumio[13845]: errno: -110, Apr 23 23:55:08 rivoplus volumio[13845]: code: 'ETIMEDOUT', Apr 23 23:55:08 rivoplus volumio[13845]: syscall: 'connect', Apr 23 23:55:08 rivoplus volumio[13845]: address: '151.101.134.79', Apr 23 23:55:08 rivoplus volumio[13845]: port: 443 Apr 23 23:55:08 rivoplus volumio[13845]: } Apr 23 23:55:08 rivoplus volumio[13845]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 23:55:09 rivoplus sudo[27370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-23 23:54 Apr 23 23:55:09 rivoplus sudo[27370]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:42:11 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="4f5519a96ae5ba7dcfda362cc37343d4"