-- Logs begin at Thu 2019-02-14 19:11:58 JST, end at Sat 2025-03-08 20:36:16 JST. --
Mar 08 20:35:00 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:04 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:05 rivo go-librespot[7318]: time="2025-03-08T20:35:05+09:00" level=debug msg="fetched chunk 9/12, size: 524288" uri="spotify:track:7MulwnmYzazj40HaMgI9aP"
Mar 08 20:35:08 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:12 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:16 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:17 rivo go-librespot[7318]: time="2025-03-08T20:35:17+09:00" level=trace msg="sent dealer ping"
Mar 08 20:35:17 rivo go-librespot[7318]: time="2025-03-08T20:35:17+09:00" level=trace msg="received dealer pong"
Mar 08 20:35:18 rivo go-librespot[7318]: time="2025-03-08T20:35:18+09:00" level=debug msg="fetched chunk 10/12, size: 524288" uri="spotify:track:7MulwnmYzazj40HaMgI9aP"
Mar 08 20:35:19 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 08 20:35:19 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 08 20:35:19 rivo volumio[3173]: info: Discovery: Getting this device information
Mar 08 20:35:19 rivo volumio[3173]: info: CoreCommandRouter::volumioGetState
Mar 08 20:35:19 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 08 20:35:20 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:24 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:28 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:30 rivo go-librespot[7318]: time="2025-03-08T20:35:30+09:00" level=debug msg="fetched chunk 11/12, size: 524288" uri="spotify:track:7MulwnmYzazj40HaMgI9aP"
Mar 08 20:35:32 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:36 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:40 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:43 rivo go-librespot[7318]: time="2025-03-08T20:35:43+09:00" level=debug msg="fetched chunk 12/12, size: 328511" uri="spotify:track:7MulwnmYzazj40HaMgI9aP"
Mar 08 20:35:44 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:47 rivo go-librespot[7318]: time="2025-03-08T20:35:47+09:00" level=trace msg="received accesspoint ping"
Mar 08 20:35:47 rivo go-librespot[7318]: time="2025-03-08T20:35:47+09:00" level=trace msg="received accesspoint pong ack"
Mar 08 20:35:47 rivo go-librespot[7318]: time="2025-03-08T20:35:47+09:00" level=trace msg="sent dealer ping"
Mar 08 20:35:47 rivo go-librespot[7318]: time="2025-03-08T20:35:47+09:00" level=trace msg="received dealer pong"
Mar 08 20:35:48 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:49 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 08 20:35:49 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 08 20:35:49 rivo volumio[3173]: info: Discovery: Getting this device information
Mar 08 20:35:49 rivo volumio[3173]: info: CoreCommandRouter::volumioGetState
Mar 08 20:35:49 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 08 20:35:52 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:35:56 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:36:00 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=debug msg="prefetching next track" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=warning msg="original track has no formats, alternatives have a total of 8" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=debug msg="selected format OGG_VORBIS_320 (0140be0d968b6954f8cec5a1c278f0e8e9e77a48)" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=debug msg="requested aes key for file 0140be0d968b6954f8cec5a1c278f0e8e9e77a48, gid: 4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=debug msg="fetched first chunk of 14, total size is 7231717 bytes" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=info msg="prefetched track \"Wrong World\" (duration: 184253ms)" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:01 rivo go-librespot[7318]: time="2025-03-08T20:36:01+09:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:4Mghgr37JNnlFWXbezg3oZ"
Mar 08 20:36:04 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:36:06 rivo volumio[3173]: info: Disabling MyMusic plugin upnp
Mar 08 20:36:06 rivo sudo[12994]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service
Mar 08 20:36:06 rivo sudo[12994]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 08 20:36:06 rivo systemd[1]: Stopping UPnP Renderer front-end to MPD...
Mar 08 20:36:06 rivo volumio[3173]: error: Upnp client error: Error: This socket has been ended by the other party
Mar 08 20:36:06 rivo volumio[3173]: ------------------------------------ BT MESSAGE: BT STATUS: running
Mar 08 20:36:08 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:36:12 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 08 20:36:15 rivo volumio[3173]: info: Enabling MyMusic plugin upnp
Mar 08 20:36:15 rivo volumio[3173]: info: Enabling plugin upnp
Mar 08 20:36:15 rivo volumio[3173]: info: Loading plugin "upnp"...
Mar 08 20:36:15 rivo volumio[3173]: info: [1741433775860] Starting Upmpd Daemon
Mar 08 20:36:15 rivo volumio[3173]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 08 20:36:15 rivo volumio[3173]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 08 20:36:15 rivo volumio[3173]: Error: listen EADDRINUSE: address already in use :::6599
Mar 08 20:36:15 rivo volumio[3173]: at Server.setupListenHandle [as _listen2] (net.js:1331:16)
Mar 08 20:36:15 rivo volumio[3173]: at listenInCluster (net.js:1379:12)
Mar 08 20:36:15 rivo volumio[3173]: at Server.listen (net.js:1465:7)
Mar 08 20:36:15 rivo volumio[3173]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17)
Mar 08 20:36:15 rivo volumio[3173]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38)
Mar 08 20:36:15 rivo volumio[3173]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19)
Mar 08 20:36:15 rivo volumio[3173]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Mar 08 20:36:15 rivo volumio[3173]: at processTicksAndRejections (internal/process/task_queues.js:77:11) {
Mar 08 20:36:15 rivo volumio[3173]: code: 'EADDRINUSE',
Mar 08 20:36:15 rivo volumio[3173]: errno: -98,
Mar 08 20:36:15 rivo volumio[3173]: syscall: 'listen',
Mar 08 20:36:15 rivo volumio[3173]: address: '::',
Mar 08 20:36:15 rivo volumio[3173]: port: 6599
Mar 08 20:36:15 rivo volumio[3173]: }
Mar 08 20:36:15 rivo volumio[3173]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 08 20:36:16 rivo sudo[13023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-08 20:35
Mar 08 20:36:16 rivo sudo[13023]: 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="a01a833dd28483f88cb390596f5090b7187992af"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="rivo"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 12:49:04 PM CET"
VOLUMIO_VERSION="3.795"
VOLUMIO_HARDWARE="mp1"
VOLUMIO_DEVICENAME="Volumio MP1"
VOLUMIO_VENDOR_MODEL="Volumio Rivo"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Rivo"
VOLUMIO_HASH="65eb03fcbe62db7e7fbed9cd39ac44df"