-- Logs begin at Mon 2025-12-22 11:38:14 AEDT, end at Tue 2025-12-23 19:57:09 AEDT. -- Dec 23 19:56:42 rivoplus volumio5-onboarding[4069]: time=2025-12-23T19:56:42.641+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 23 19:56:42 rivoplus volumio5-onboarding[4069]: time=2025-12-23T19:56:42.827+11:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 23 19:56:44 rivoplus volumio[3105]: info: Starting UPNP Playback Dec 23 19:56:44 rivoplus volumio[3105]: info: Preparing playback through UPNP Dec 23 19:56:44 rivoplus volumio[3105]: info: Consume mode Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreCommandRouter::volumioGetState Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 23 19:56:44 rivoplus volumio[3105]: info: Clearing queue after UPNP request Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreStateMachine::ClearQueue Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreStateMachine::stop Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 23 19:56:44 rivoplus volumio[3105]: info: CorePlayQueue::clearPlayQueue Dec 23 19:56:44 rivoplus volumio[3105]: info: CorePlayQueue::saveQueue Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreCommandRouter::volumioPushState Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreCommandRouter::volumioGetState Dec 23 19:56:44 rivoplus volumio[3105]: info: CorePlayQueue::getTrack 3 Dec 23 19:56:44 rivoplus volumio[3105]: info: CoreCommandRouter::volumioPushQueue Dec 23 19:56:45 rivoplus volumio[3105]: info: Dec 23 19:56:45 rivoplus volumio[3105]: ---------------------------- MPD announces system playlist update Dec 23 19:56:45 rivoplus volumio[3105]: info: Ignoring MPD Status Update Dec 23 19:56:45 rivoplus volumio[3105]: error: updateQueue error: null Dec 23 19:56:45 rivoplus volumio[3105]: info: ------------------------------ 4ms Dec 23 19:56:45 rivoplus volumio[3105]: info: Starting UPNP Playback Dec 23 19:56:45 rivoplus volumio[3105]: info: Preparing playback through UPNP Dec 23 19:56:45 rivoplus volumio[3105]: info: CoreCommandRouter::volumioGetState Dec 23 19:56:45 rivoplus volumio[3105]: info: CorePlayQueue::getTrack 3 Dec 23 19:56:45 rivoplus volumio[3105]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 23 19:56:45 rivoplus volumio5-onboarding[4069]: time=2025-12-23T19:56:45.407+11:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 23 19:56:45 rivoplus volumio5-onboarding[4069]: time=2025-12-23T19:56:45.826+11:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 23 19:56:57 rivoplus volumio[3105]: info: CoreCommandRouter::volumioGetState Dec 23 19:57:00 rivoplus volumio[3105]: info: Executing endpoint metavolumio Dec 23 19:57:00 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 23 19:57:00 rivoplus volumio[3105]: info: Executing endpoint metavolumio Dec 23 19:57:00 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 23 19:57:00 rivoplus volumio[3105]: info: Executing endpoint metavolumio Dec 23 19:57:00 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 23 19:57:02 rivoplus volumio[3105]: info: Retrieving Cloud Streaming UI Dec 23 19:57:02 rivoplus volumio[3105]: info: Getting Tidal Cloud Configuration Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 23 19:57:02 rivoplus volumio[3105]: info: Getting Qobuz Cloud Configuration Dec 23 19:57:02 rivoplus volumio[3105]: info: Asking plugin for UI Config Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 23 19:57:02 rivoplus volumio[3105]: info: Getting Spotify Cloud Configuration Dec 23 19:57:02 rivoplus volumio[3105]: info: Asking plugin for UI Config Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 23 19:57:02 rivoplus volumio[3105]: info: Saving Spotify Acccount Dec 23 19:57:02 rivoplus volumio[3105]: info: Got it Dec 23 19:57:02 rivoplus volumio[3105]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 23 19:57:02 rivoplus volumio[3105]: info: Got Tidal Cloud Configuration Dec 23 19:57:02 rivoplus volumio[3105]: info: Got it Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::volumioGetBrowseSources Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::volumioGetBrowseSources Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::volumioGetBrowseSources Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 23 19:57:02 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 23 19:57:06 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 23 19:57:07 rivoplus volumio[3105]: info: Disabling MyMusic plugin upnp Dec 23 19:57:07 rivoplus sudo[10502]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Dec 23 19:57:07 rivoplus sudo[10502]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 23 19:57:07 rivoplus systemd[1]: Stopping UPnP Renderer front-end to MPD... Dec 23 19:57:07 rivoplus volumio[3105]: error: Upnp client error: Error: This socket has been ended by the other party Dec 23 19:57:08 rivoplus volumio[3105]: info: Enabling MyMusic plugin upnp Dec 23 19:57:08 rivoplus volumio[3105]: info: Enabling plugin upnp Dec 23 19:57:08 rivoplus volumio[3105]: info: Loading plugin "upnp"... Dec 23 19:57:08 rivoplus volumio[3105]: info: [1766480228392] Starting Upmpd Daemon Dec 23 19:57:08 rivoplus volumio[3105]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 23 19:57:08 rivoplus volumio[3105]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 23 19:57:08 rivoplus volumio[3105]: Error: listen EADDRINUSE: address already in use :::6599 Dec 23 19:57:08 rivoplus volumio[3105]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Dec 23 19:57:08 rivoplus volumio[3105]: at listenInCluster (net.js:1379:12) Dec 23 19:57:08 rivoplus volumio[3105]: at Server.listen (net.js:1465:7) Dec 23 19:57:08 rivoplus volumio[3105]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Dec 23 19:57:08 rivoplus volumio[3105]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Dec 23 19:57:08 rivoplus volumio[3105]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 23 19:57:08 rivoplus volumio[3105]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 23 19:57:08 rivoplus volumio[3105]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Dec 23 19:57:08 rivoplus volumio[3105]: code: 'EADDRINUSE', Dec 23 19:57:08 rivoplus volumio[3105]: errno: -98, Dec 23 19:57:08 rivoplus volumio[3105]: syscall: 'listen', Dec 23 19:57:08 rivoplus volumio[3105]: address: '::', Dec 23 19:57:08 rivoplus volumio[3105]: port: 6599 Dec 23 19:57:08 rivoplus volumio[3105]: } Dec 23 19:57:08 rivoplus volumio[3105]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 23 19:57:09 rivoplus sudo[10513]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-23 19:56 Dec 23 19:57:09 rivoplus sudo[10513]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:47:33 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="9e8aa5d6afb5e5d87a87bafae7aa5647"