-- Logs begin at Thu 2025-06-12 09:58:36 CEST, end at Thu 2025-06-12 16:04:10 CEST. -- Jun 12 16:03:00 primo volumio[3176]: info: Clearing queue after UPNP request Jun 12 16:03:00 primo volumio[3176]: info: CoreStateMachine::ClearQueue Jun 12 16:03:00 primo volumio[3176]: info: CoreStateMachine::stop Jun 12 16:03:00 primo volumio[3176]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 12 16:03:00 primo volumio[3176]: info: CorePlayQueue::clearPlayQueue Jun 12 16:03:00 primo volumio[3176]: info: CorePlayQueue::saveQueue Jun 12 16:03:00 primo volumio[3176]: info: CoreCommandRouter::volumioPushState Jun 12 16:03:00 primo volumio[3176]: info: CoreCommandRouter::volumioGetState Jun 12 16:03:00 primo volumio[3176]: info: CorePlayQueue::getTrack 0 Jun 12 16:03:00 primo volumio[3176]: info: MRS: Pushing multiroomSync output update for this device Jun 12 16:03:00 primo volumio[3176]: info: MRS: Pushing multiroomSync output Jun 12 16:03:00 primo volumio[3176]: info: CoreCommandRouter::volumioPushQueue Jun 12 16:03:00 primo volumio[3176]: info: Updating RAAT Signal Path Jun 12 16:03:00 primo volumio[3176]: info: Jun 12 16:03:00 primo volumio[3176]: ---------------------------- MPD announces system playlist update Jun 12 16:03:00 primo volumio[3176]: info: Ignoring MPD Status Update Jun 12 16:03:00 primo volumio[3176]: info: Jun 12 16:03:00 primo volumio[3176]: ---------------------------- MPD announces system playlist update Jun 12 16:03:00 primo volumio[3176]: info: Ignoring MPD Status Update Jun 12 16:03:00 primo volumio[3176]: error: updateQueue error: null Jun 12 16:03:00 primo volumio[3176]: error: updateQueue error: null Jun 12 16:03:00 primo volumio[3176]: info: ------------------------------ 4ms Jun 12 16:03:00 primo volumio[3176]: info: ------------------------------ 2ms Jun 12 16:03:00 primo volumio[3176]: info: Starting UPNP Playback Jun 12 16:03:00 primo volumio[3176]: info: Preparing playback through UPNP Jun 12 16:03:00 primo volumio[3176]: info: CoreCommandRouter::volumioGetState Jun 12 16:03:00 primo volumio[3176]: info: CorePlayQueue::getTrack 0 Jun 12 16:03:00 primo volumio[3176]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 12 16:03:00 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 16:03:00 primo volumio[3176]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Stubborn Love (Acoustic)","artist":"Larkin Poe","album":"An Acoustic Companion","duration":"218","uri":"http://192.168.178.43:49152/audirvana/audio_0_0.wav","service":""} Jun 12 16:03:09 primo go-librespot[5999]: time="2025-06-12T16:03:09+02:00" level=trace msg="sent dealer ping" Jun 12 16:03:09 primo go-librespot[5999]: time="2025-06-12T16:03:09+02:00" level=trace msg="received dealer pong" Jun 12 16:03:39 primo go-librespot[5999]: time="2025-06-12T16:03:39+02:00" level=trace msg="sent dealer ping" Jun 12 16:03:39 primo go-librespot[5999]: time="2025-06-12T16:03:39+02:00" level=trace msg="received dealer pong" Jun 12 16:03:40 primo volumio[3815]: 100 Jun 12 16:03:40 primo volumio[3815]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 12 16:03:40 primo volumio[3815]: Dload Upload Total Spent Left Speed Jun 12 16:03:40 primo volumio[3176]: info: Jun 12 16:03:40 primo volumio[3176]: ---------------------------- Client requests Volume 100 Jun 12 16:03:40 primo volumio[3176]: info: VolumeController::SetAlsaVolume100 Jun 12 16:03:40 primo volumio[3176]: info: CoreStateMachine::pushState Jun 12 16:03:40 primo volumio[3176]: info: CoreCommandRouter::volumioPushState Jun 12 16:03:40 primo volumio[3176]: info: CoreCommandRouter::volumioGetState Jun 12 16:03:40 primo volumio[3176]: info: MRS: Pushing multiroomSync output update for this device Jun 12 16:03:40 primo volumio[3176]: info: MRS: Pushing multiroomSync output Jun 12 16:03:40 primo volumio[3815]: [158B blob data] Jun 12 16:03:40 primo volumio[3815]: {"time":1749737020913,"response":"volume Success"}100 Jun 12 16:03:40 primo volumio[3176]: info: Updating RAAT Signal Path Jun 12 16:03:41 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 16:03:41 primo volumio[3176]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Stubborn Love (Acoustic)","artist":"Larkin Poe","album":"An Acoustic Companion","duration":"218","uri":"http://192.168.178.43:49152/audirvana/audio_0_0.wav","service":""} Jun 12 16:03:43 primo volumio[3176]: info: Executing endpoint metavolumio Jun 12 16:03:43 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 12 16:03:43 primo volumio[3176]: info: Executing endpoint metavolumio Jun 12 16:03:43 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 12 16:03:43 primo volumio[3176]: info: Executing endpoint metavolumio Jun 12 16:03:43 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 12 16:03:57 primo volumio[3176]: info: Retrieving Cloud Streaming UI Jun 12 16:03:57 primo volumio[3176]: info: Getting Tidal Cloud Configuration Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 12 16:03:57 primo volumio[3176]: info: Getting Qobuz Cloud Configuration Jun 12 16:03:57 primo volumio[3176]: info: Asking plugin for UI Config Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 12 16:03:57 primo volumio[3176]: info: Getting Spotify Cloud Configuration Jun 12 16:03:57 primo volumio[3176]: info: Asking plugin for UI Config Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 12 16:03:57 primo volumio[3176]: info: Saving Spotify Acccount Jun 12 16:03:57 primo volumio[3176]: info: Got it Jun 12 16:03:57 primo volumio[3176]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 12 16:03:57 primo volumio[3176]: info: Got Tidal Cloud Configuration Jun 12 16:03:57 primo volumio[3176]: info: Got it Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::volumioGetBrowseSources Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::volumioGetBrowseSources Jun 12 16:03:57 primo volumio[3176]: info: CoreCommandRouter::volumioGetBrowseSources Jun 12 16:03:58 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 12 16:03:58 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 12 16:04:00 primo volumio[3176]: info: Disabling MyMusic plugin upnp Jun 12 16:04:01 primo sudo[30345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jun 12 16:04:01 primo sudo[30345]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 16:04:01 primo systemd[1]: Stopping UPnP Renderer front-end to MPD... Jun 12 16:04:01 primo volumio[3176]: error: Upnp client error: Error: This socket has been ended by the other party Jun 12 16:04:01 primo volumio[3176]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 12 16:04:02 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 12 16:04:06 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 12 16:04:09 primo go-librespot[5999]: time="2025-06-12T16:04:09+02:00" level=trace msg="sent dealer ping" Jun 12 16:04:09 primo go-librespot[5999]: time="2025-06-12T16:04:09+02:00" level=trace msg="received dealer pong" Jun 12 16:04:10 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 12 16:04:10 primo volumio[3176]: info: Enabling MyMusic plugin upnp Jun 12 16:04:10 primo volumio[3176]: info: Enabling plugin upnp Jun 12 16:04:10 primo volumio[3176]: info: Loading plugin "upnp"... Jun 12 16:04:10 primo volumio[3176]: info: [1749737050110] Starting Upmpd Daemon Jun 12 16:04:10 primo volumio[3176]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 12 16:04:10 primo volumio[3176]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 12 16:04:10 primo volumio[3176]: Error: listen EADDRINUSE: address already in use :::6599 Jun 12 16:04:10 primo volumio[3176]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jun 12 16:04:10 primo volumio[3176]: at listenInCluster (net.js:1379:12) Jun 12 16:04:10 primo volumio[3176]: at Server.listen (net.js:1465:7) Jun 12 16:04:10 primo volumio[3176]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jun 12 16:04:10 primo volumio[3176]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jun 12 16:04:10 primo volumio[3176]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jun 12 16:04:10 primo volumio[3176]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 12 16:04:10 primo volumio[3176]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jun 12 16:04:10 primo volumio[3176]: code: 'EADDRINUSE', Jun 12 16:04:10 primo volumio[3176]: errno: -98, Jun 12 16:04:10 primo volumio[3176]: syscall: 'listen', Jun 12 16:04:10 primo volumio[3176]: address: '::', Jun 12 16:04:10 primo volumio[3176]: port: 6599 Jun 12 16:04:10 primo volumio[3176]: } Jun 12 16:04:10 primo volumio[3176]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 12 16:04:10 primo sudo[30376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-12 16:03 Jun 12 16:04:10 primo sudo[30376]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 07:34:23 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="c7ccfd1c436e37df77d047f13edf35d7"