-- Logs begin at Fri 2024-11-29 20:16:38 JST, end at Sun 2024-12-01 20:45:38 JST. -- Dec 01 20:44:16 rivo volumio[3112]: info: CoreCommandRouter::volumioGetState Dec 01 20:44:18 rivo volumio[3112]: info: Executing endpoint metavolumio Dec 01 20:44:18 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 20:44:18 rivo volumio[3112]: info: Executing endpoint metavolumio Dec 01 20:44:18 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 20:44:18 rivo volumio[3112]: info: Executing endpoint metavolumio Dec 01 20:44:18 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 01 20:44:23 rivo volumio[3112]: info: Retrieving Cloud Streaming UI Dec 01 20:44:23 rivo volumio[3112]: info: Getting Tidal Cloud Configuration Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 01 20:44:23 rivo volumio[3112]: info: Getting Qobuz Cloud Configuration Dec 01 20:44:23 rivo volumio[3112]: info: Asking plugin for UI Config Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 01 20:44:23 rivo volumio[3112]: info: Getting Spotify Cloud Configuration Dec 01 20:44:23 rivo volumio[3112]: info: Asking plugin for UI Config Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 01 20:44:23 rivo volumio[3112]: info: Saving Spotify Acccount Dec 01 20:44:23 rivo volumio[3112]: info: Got it Dec 01 20:44:23 rivo volumio[3112]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 01 20:44:23 rivo volumio[3112]: info: Got Tidal Cloud Configuration Dec 01 20:44:23 rivo volumio[3112]: info: Got it Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::volumioGetBrowseSources Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::volumioGetBrowseSources Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::volumioGetBrowseSources Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 01 20:44:27 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:31 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:35 rivo volumio[3112]: info: Disabling MyMusic plugin upnp Dec 01 20:44:35 rivo sudo[9444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Dec 01 20:44:35 rivo sudo[9444]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 20:44:35 rivo systemd[1]: Stopping UPnP Renderer front-end to MPD... Dec 01 20:44:35 rivo volumio[3112]: error: Upnp client error: Error: This socket has been ended by the other party Dec 01 20:44:35 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:39 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:43 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:47 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:51 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:55 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:44:56 rivo volumio[3112]: info: CorePlayQueue::getTrack 6 Dec 01 20:44:56 rivo volumio[3112]: info: CorePlayQueue::getTrack 7 Dec 01 20:44:56 rivo volumio[3112]: info: Prefetching next song Dec 01 20:44:56 rivo volumio[3112]: info: [1733053496662] ControllerTidal::prefetch Dec 01 20:44:56 rivo volumio[3112]: info: Getting stream with soundQuality HI_RES Dec 01 20:44:56 rivo volumio[3112]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/3234386&soundQuality=HI_RES" Dec 01 20:44:56 rivo volumio[3112]: info: Dec 01 20:44:56 rivo volumio[3112]: ---------------------------- MPD announces system playlist update Dec 01 20:44:56 rivo volumio[3112]: info: Ignoring MPD Status Update Dec 01 20:44:56 rivo volumio[3112]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/3234386&soundQuality=HI_RES" took 3 milliseconds Dec 01 20:44:56 rivo volumio[3112]: STREAMING PROXY: Handling url /?data=tidal://song/3234386&soundQuality=HI_RES Dec 01 20:44:56 rivo volumio[3112]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 01 20:44:56 rivo volumio[3112]: verbose: ControllerMpd::sendMpdCommand consume 1 Dec 01 20:44:56 rivo volumio[3112]: info: ------------------------------ 3ms Dec 01 20:44:56 rivo volumio[3112]: info: sendMpdCommand consume 1 took 2 milliseconds Dec 01 20:44:56 rivo volumio[3112]: info: Executing endpoint getStreamUrltidal Dec 01 20:44:56 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Dec 01 20:44:57 rivo volumio[3112]: info: getStreamUrl took 787 milliseconds Dec 01 20:44:57 rivo volumio[3112]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5ZDVjMzc4OGQwMTdmYjI2MDk1N2EyY2EzYjBjMzU1Zi5tcDQ/0.flac?Expires=1733057097&Signature=wegrjrxXKnF9Y2nwULo~VovxKrsshevrN1yJMB6abi8QIg5a9GrS5kNLAG1VHU8-bIOWUOlpU8Fz2wLHod6urKc8GZgTW9wgz6OlnSufdYS3FczPx228l5V-4~ZmZyEwsaUIpXm1KGbadqPHFLZeYm93hBw4KGoGELoBKqvzgaMjREsxK1jitJlSY~Q~u1RSV6phX4O2g0Xl3TgHPcfO5X9~hpyqOxS1JxcLs79RWqMd47sl~cWhBHHnQsZly~xyFDW184o5wlWlGQ25NB8zeqMXK4Vsaw3sSGfKNmlQnJUQOlAgdl8sl1906ZM1f~je3ez-c1TJJ15GYrGUNwesZw__&Key-Pair-Id=K14LZCZ9QUI4JL Dec 01 20:44:58 rivo volumio[3112]: STREAMING PROXY: Response: 200, length: 32241713 Dec 01 20:44:59 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:00 rivo volumio[3112]: info: Dec 01 20:45:00 rivo volumio[3112]: ---------------------------- MPD announces system playlist update Dec 01 20:45:00 rivo volumio[3112]: info: Ignoring MPD Status Update Dec 01 20:45:00 rivo volumio[3112]: info: Dec 01 20:45:00 rivo volumio[3112]: ---------------------------- MPD announces state update: player Dec 01 20:45:00 rivo volumio[3112]: info: ControllerMpd::getState Dec 01 20:45:00 rivo volumio[3112]: verbose: ControllerMpd::sendMpdCommand status Dec 01 20:45:00 rivo volumio[3112]: info: ------------------------------ 4ms Dec 01 20:45:00 rivo volumio[3112]: info: sendMpdCommand status took 8 milliseconds Dec 01 20:45:00 rivo volumio[3112]: verbose: ControllerMpd::parseState Dec 01 20:45:00 rivo volumio[3112]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 20:45:00 rivo volumio[3112]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 01 20:45:00 rivo volumio[3112]: verbose: ControllerMpd::parseTrackInfo Dec 01 20:45:00 rivo volumio[3112]: info: ControllerMpd::pushState Dec 01 20:45:00 rivo volumio[3112]: info: CoreCommandRouter::servicePushState Dec 01 20:45:00 rivo volumio[3112]: info: CorePlayQueue::getTrack 6 Dec 01 20:45:00 rivo volumio[3112]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":526,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"423 Kbps","isStreaming":false,"title":"3234386&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/3234386&soundQuality=HI_RES","trackType":"tidal"} Dec 01 20:45:00 rivo volumio[3112]: verbose: CURRENT POSITION 6 Dec 01 20:45:00 rivo volumio[3112]: info: CoreStateMachine::syncState stateService play Dec 01 20:45:00 rivo volumio[3112]: info: CoreStateMachine::syncState currentStatus play Dec 01 20:45:00 rivo volumio[3112]: info: Received an update from plugin. extracting info from payload Dec 01 20:45:00 rivo volumio[3112]: info: CoreStateMachine::pushState Dec 01 20:45:00 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 20:45:00 rivo volumio[3112]: info: CoreCommandRouter::volumioPushState Dec 01 20:45:00 rivo volumio[3112]: info: CoreStateMachine::pushState Dec 01 20:45:00 rivo volumio[3112]: info: CoreCommandRouter::volumioPushState Dec 01 20:45:00 rivo volumio[3112]: info: ------------------------------ 23ms Dec 01 20:45:01 rivo volumio[3112]: info: CoreStateMachine::startPlaybackTimer Dec 01 20:45:01 rivo volumio[3112]: info: CorePlayQueue::getTrack 7 Dec 01 20:45:01 rivo volumio[3112]: info: CoreStateMachine::pushState Dec 01 20:45:01 rivo volumio[3112]: info: CorePlayQueue::getTrack 7 Dec 01 20:45:01 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 20:45:01 rivo volumio[3112]: info: CoreCommandRouter::volumioPushState Dec 01 20:45:03 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:07 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:11 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:15 rivo volumio[3112]: STREAMING PROXY: Client dropped request, destroying Dec 01 20:45:15 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:19 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:23 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:27 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:31 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:35 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 01 20:45:37 rivo volumio[3112]: info: Enabling MyMusic plugin upnp Dec 01 20:45:37 rivo volumio[3112]: info: Enabling plugin upnp Dec 01 20:45:37 rivo volumio[3112]: info: Loading plugin "upnp"... Dec 01 20:45:37 rivo volumio[3112]: info: [1733053537418] Starting Upmpd Daemon Dec 01 20:45:37 rivo volumio[3112]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 01 20:45:37 rivo volumio[3112]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 20:45:37 rivo volumio[3112]: Error: listen EADDRINUSE: address already in use :::6599 Dec 01 20:45:37 rivo volumio[3112]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Dec 01 20:45:37 rivo volumio[3112]: at listenInCluster (net.js:1379:12) Dec 01 20:45:37 rivo volumio[3112]: at Server.listen (net.js:1465:7) Dec 01 20:45:37 rivo volumio[3112]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Dec 01 20:45:37 rivo volumio[3112]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Dec 01 20:45:37 rivo volumio[3112]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 01 20:45:37 rivo volumio[3112]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 01 20:45:37 rivo volumio[3112]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Dec 01 20:45:37 rivo volumio[3112]: code: 'EADDRINUSE', Dec 01 20:45:37 rivo volumio[3112]: errno: -98, Dec 01 20:45:37 rivo volumio[3112]: syscall: 'listen', Dec 01 20:45:37 rivo volumio[3112]: address: '::', Dec 01 20:45:37 rivo volumio[3112]: port: 6599 Dec 01 20:45:37 rivo volumio[3112]: } Dec 01 20:45:37 rivo volumio[3112]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 20:45:38 rivo sudo[9737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-12-01 20:44 Dec 01 20:45:38 rivo sudo[9737]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"