-- Logs begin at Fri 2025-07-04 21:08:30 CEST, end at Fri 2025-07-04 21:19:28 CEST. -- Jul 04 21:18:00 mediaserver go-librespot[1382]: time="2025-07-04T21:18:00+02:00" level=trace msg="sent dealer ping" Jul 04 21:18:01 mediaserver go-librespot[1382]: time="2025-07-04T21:18:01+02:00" level=trace msg="received dealer pong" Jul 04 21:18:05 mediaserver go-librespot[1382]: time="2025-07-04T21:18:05+02:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:2ENexcMEMsYk0rVJigVD3i" Jul 04 21:18:18 mediaserver go-librespot[1382]: time="2025-07-04T21:18:18+02:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:2ENexcMEMsYk0rVJigVD3i" Jul 04 21:18:30 mediaserver go-librespot[1382]: time="2025-07-04T21:18:30+02:00" level=trace msg="sent dealer ping" Jul 04 21:18:31 mediaserver go-librespot[1382]: time="2025-07-04T21:18:31+02:00" level=trace msg="received dealer pong" Jul 04 21:18:32 mediaserver go-librespot[1382]: time="2025-07-04T21:18:32+02:00" level=debug msg="fetched chunk 9/18, size: 524288" uri="spotify:track:2ENexcMEMsYk0rVJigVD3i" Jul 04 21:18:44 mediaserver go-librespot[1382]: time="2025-07-04T21:18:44+02:00" level=debug msg="fetched chunk 10/18, size: 524288" uri="spotify:track:2ENexcMEMsYk0rVJigVD3i" Jul 04 21:18:54 mediaserver go-librespot[1382]: time="2025-07-04T21:18:54+02:00" level=debug msg="handling pause player command from 0f2a4cd337de87cf3d9be8463cb75d91a77da684" Jul 04 21:18:54 mediaserver go-librespot[1382]: time="2025-07-04T21:18:54+02:00" level=debug msg="pause track at 101132ms" Jul 04 21:18:54 mediaserver go-librespot[1382]: time="2025-07-04T21:18:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 04 21:18:54 mediaserver go-librespot[1382]: time="2025-07-04T21:18:54+02:00" level=debug msg="sending successful reply for dealer request" Jul 04 21:18:55 mediaserver go-librespot[1382]: time="2025-07-04T21:18:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 04 21:18:55 mediaserver go-librespot[1382]: time="2025-07-04T21:18:55+02:00" level=trace msg="emitting websocket event: paused" Jul 04 21:18:55 mediaserver volumio[759]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2ENexcMEMsYk0rVJigVD3i","play_origin":"playlist"}} Jul 04 21:18:55 mediaserver volumio[759]: SPOTIFY: PUSH STATE SPOTIFY Jul 04 21:18:55 mediaserver volumio[759]: SPOTIFY: {"status":"pause","service":"spop","title":"Only Girl (In The World)","artist":"Rihanna","album":"Loud (Japan Version)","albumart":"https://i.scdn.co/image/ab67616d00001e0231548865f7c729290b96c794","uri":"spotify:track:2ENexcMEMsYk0rVJigVD3i","trackType":"spotify","seek":102000,"duration":235,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 04 21:18:55 mediaserver volumio[759]: info: CoreCommandRouter::servicePushState Jul 04 21:18:55 mediaserver volumio[759]: info: CoreStateMachine::pushState Jul 04 21:18:55 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 21:18:55 mediaserver volumio[759]: info: CoreCommandRouter::volumioPushState Jul 04 21:18:55 mediaserver volumio[759]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Jul 04 21:19:00 mediaserver go-librespot[1382]: time="2025-07-04T21:19:00+02:00" level=info msg="playback was transferred to " Jul 04 21:19:00 mediaserver go-librespot[1382]: time="2025-07-04T21:19:00+02:00" level=trace msg="closed output device because of stop command" Jul 04 21:19:00 mediaserver go-librespot[1382]: time="2025-07-04T21:19:00+02:00" level=debug msg="put connect state inactive" Jul 04 21:19:00 mediaserver go-librespot[1382]: time="2025-07-04T21:19:00+02:00" level=trace msg="emitting websocket event: inactive" Jul 04 21:19:00 mediaserver go-librespot[1382]: time="2025-07-04T21:19:00+02:00" level=trace msg="emitting websocket event: stopped" Jul 04 21:19:00 mediaserver volumio[759]: SPOTIFY: received: {"type":"inactive","data":null} Jul 04 21:19:00 mediaserver volumio[759]: error: Failed to decode event: inactive Jul 04 21:19:00 mediaserver volumio[759]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Jul 04 21:19:00 mediaserver volumio[759]: SPOTIFY: PUSH STATE SPOTIFY Jul 04 21:19:00 mediaserver volumio[759]: SPOTIFY: {"status":"stop","service":"spop","title":"Only Girl (In The World)","artist":"Rihanna","album":"Loud (Japan Version)","albumart":"https://i.scdn.co/image/ab67616d00001e0231548865f7c729290b96c794","uri":"spotify:track:2ENexcMEMsYk0rVJigVD3i","trackType":"spotify","seek":102000,"duration":235,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 04 21:19:00 mediaserver volumio[759]: info: CoreCommandRouter::servicePushState Jul 04 21:19:00 mediaserver volumio[759]: info: CoreStateMachine::pushState Jul 04 21:19:00 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 21:19:00 mediaserver volumio[759]: info: CoreCommandRouter::volumioPushState Jul 04 21:19:00 mediaserver volumio[759]: info: CorePlayQueue::getTrack 0 Jul 04 21:19:00 mediaserver volumio[759]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Only Girl (In The World)","artist":"Rihanna","album":"Loud (Japan Version)","albumart":"https://i.scdn.co/image/ab67616d00001e0231548865f7c729290b96c794","uri":"spotify:track:2ENexcMEMsYk0rVJigVD3i","trackType":"spotify","seek":102000,"duration":235,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 04 21:19:00 mediaserver volumio[759]: verbose: CURRENT POSITION 0 Jul 04 21:19:00 mediaserver volumio[759]: info: CoreStateMachine::syncState stateService stop Jul 04 21:19:00 mediaserver volumio[759]: info: CoreStateMachine::syncState currentStatus pause Jul 04 21:19:00 mediaserver volumio[759]: info: CoreStateMachine::pushState Jul 04 21:19:00 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 04 21:19:00 mediaserver volumio[759]: info: CoreCommandRouter::volumioPushState Jul 04 21:19:00 mediaserver volumio[759]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Jul 04 21:19:00 mediaserver volumio[759]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Jul 04 21:19:00 mediaserver go-librespot[1382]: time="2025-07-04T21:19:00+02:00" level=debug msg="dealer connection closed" Jul 04 21:19:00 mediaserver go-librespot[1382]: time="2025-07-04T21:19:00+02:00" level=debug msg="dealer recv loop stopped" Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 21:19:24 mediaserver volumio[759]: info: Retrieving Cloud Streaming UI Jul 04 21:19:24 mediaserver volumio[759]: info: Getting Tidal Cloud Configuration Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 21:19:24 mediaserver volumio[759]: info: Getting Qobuz Cloud Configuration Jul 04 21:19:24 mediaserver volumio[759]: info: Asking plugin for UI Config Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 21:19:24 mediaserver volumio[759]: info: Getting Spotify Cloud Configuration Jul 04 21:19:24 mediaserver volumio[759]: info: Asking plugin for UI Config Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 21:19:24 mediaserver volumio[759]: info: Saving Spotify Acccount Jul 04 21:19:24 mediaserver volumio[759]: info: Got Tidal Cloud Configuration Jul 04 21:19:24 mediaserver volumio[759]: info: Got it Jul 04 21:19:24 mediaserver volumio[759]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 04 21:19:24 mediaserver volumio[759]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::volumioGetBrowseSources Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::volumioGetBrowseSources Jul 04 21:19:24 mediaserver volumio[759]: info: CoreCommandRouter::volumioGetBrowseSources Jul 04 21:19:25 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 04 21:19:25 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 04 21:19:28 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jul 04 21:19:28 mediaserver volumio[759]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jul 04 21:19:28 mediaserver volumio[759]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 21:19:28 mediaserver volumio[759]: Error: getaddrinfo -3007 Jul 04 21:19:28 mediaserver volumio[759]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) Jul 04 21:19:28 mediaserver volumio[759]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) Jul 04 21:19:28 mediaserver volumio[759]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { Jul 04 21:19:28 mediaserver volumio[759]: code: -3007, Jul 04 21:19:28 mediaserver volumio[759]: errno: -3007, Jul 04 21:19:28 mediaserver volumio[759]: syscall: 'getaddrinfo' Jul 04 21:19:28 mediaserver volumio[759]: } Jul 04 21:19:28 mediaserver volumio[759]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 04 21:19:28 mediaserver sudo[3325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-04 21:18 Jul 04 21:19:28 mediaserver sudo[3325]: 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="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:41:06 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="097e6b8b481766e7a0f9527e4a34a29b"