-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Wed 2025-07-16 09:58:20 CEST. -- Jul 16 09:57:00 garaz-volumio volumio[2676]: info: go-librespot daemon successfully initialized Jul 16 09:57:03 garaz-volumio volumio[2676]: info: Initializing connection to go-librespot Websocket Jul 16 09:57:04 garaz-volumio volumio[2676]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 16 09:57:16 garaz-volumio volumio[2676]: info: AutoStart - Plugin is starting Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreCommandRouter::volumioGetQueue Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::getQueue Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CorePlayQueue::getQueue Jul 16 09:57:16 garaz-volumio volumio[2676]: info: AutoStart - start playing Jul 16 09:57:16 garaz-volumio volumio[2676]: info: AutoStart - start playing with no specific position Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreCommandRouter::volumioPlay Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::play index 0 Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::stop Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::play index undefined Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CorePlayQueue::getTrack 0 Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CoreStateMachine::startPlaybackTimer Jul 16 09:57:16 garaz-volumio volumio[2676]: info: CorePlayQueue::getTrack 0 Jul 16 09:57:16 garaz-volumio volumio[2676]: info: [1752652636168] ControllerWebradio::clearAddPlayTrack Jul 16 09:57:16 garaz-volumio volumio[2676]: verbose: ControllerMpd::sendMpdCommand stop Jul 16 09:57:16 garaz-volumio volumio[2676]: info: sendMpdCommand stop took 4 milliseconds Jul 16 09:57:16 garaz-volumio volumio[2676]: verbose: ControllerMpd::sendMpdCommand clear Jul 16 09:57:16 garaz-volumio volumio[2676]: info: Jul 16 09:57:16 garaz-volumio volumio[2676]: ---------------------------- MPD announces system playlist update Jul 16 09:57:16 garaz-volumio volumio[2676]: info: Ignoring MPD Status Update Jul 16 09:57:16 garaz-volumio volumio[2676]: info: sendMpdCommand clear took 8 milliseconds Jul 16 09:57:16 garaz-volumio volumio[2676]: verbose: ControllerMpd::sendMpdCommand load "https://stream.bauermedia.sk/europa2.mp3" Jul 16 09:57:16 garaz-volumio volumio[2676]: info: Jul 16 09:57:16 garaz-volumio volumio[2676]: ---------------------------- MPD announces system playlist update Jul 16 09:57:16 garaz-volumio volumio[2676]: info: Ignoring MPD Status Update Jul 16 09:57:16 garaz-volumio volumio[2676]: info: Jul 16 09:57:16 garaz-volumio volumio[2676]: ---------------------------- MPD announces system playlist update Jul 16 09:57:16 garaz-volumio volumio[2676]: info: Ignoring MPD Status Update Jul 16 09:57:16 garaz-volumio volumio[2676]: error: updateQueue error: null Jul 16 09:57:16 garaz-volumio volumio[2676]: info: ------------------------------ 24ms Jul 16 09:57:19 garaz-volumio volumio[2676]: error: MyVolumio Plugin failed to start in a timely fashion Jul 16 09:57:19 garaz-volumio volumio[2676]: [Metrics] CommandRouter: 44s 754.15ms Jul 16 09:57:19 garaz-volumio volumio[2676]: info: CoreCommandRouter::volumiosetStartupVolume Jul 16 09:57:19 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 16 09:57:19 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 16 09:57:19 garaz-volumio volumio[2676]: info: CoreCommandRouter::Close All Modals sent Jul 16 09:57:19 garaz-volumio volumio[2676]: info: CoreCommandRouter::Close All Modals sent Jul 16 09:57:20 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jul 16 09:57:20 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 16 09:57:20 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jul 16 09:57:21 garaz-volumio ntpd[682]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jul 16 09:57:25 garaz-volumio go-librespot[2879]: time="2025-07-16T09:57:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 16 09:57:25 garaz-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 16 09:57:25 garaz-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 16 09:57:26 garaz-volumio volumio[2676]: info: BOOT COMPLETED Jul 16 09:57:26 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 16 09:57:26 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 16 09:57:26 garaz-volumio volumio[2676]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 16 09:57:28 garaz-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 16 09:57:28 garaz-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jul 16 09:57:28 garaz-volumio systemd[1]: Stopped go-librespot Daemon. Jul 16 09:57:28 garaz-volumio systemd[1]: Started go-librespot Daemon. Jul 16 09:57:28 garaz-volumio go-librespot[3023]: Librespot-go daemon starting... Jul 16 09:57:28 garaz-volumio go-librespot[3023]: time="2025-07-16T09:57:28+02:00" level=info msg="generated new device id: 9c4debe99c0f2f587def6192683f6b750bcf829d" Jul 16 09:57:28 garaz-volumio go-librespot[3023]: time="2025-07-16T09:57:28+02:00" level=debug msg="stored credentials found for 31ykrfcoejvq3eri6uosxaghgvou" Jul 16 09:57:32 garaz-volumio mpd_monitor.sh[503]: MPD Monitor Service: MPD Appears to be inactive, restarting Jul 16 09:57:32 garaz-volumio systemd[1]: Stopping Music Player Daemon... Jul 16 09:57:33 garaz-volumio ntpd[682]: Soliciting pool server 2a03:1d87:1:1303::56:5 Jul 16 09:57:34 garaz-volumio volumio[2676]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.819&uuid=70c06b48de3d14bcf18d3b7865feb41e" http://updates.volumio.org/downloader-v1/track-device Jul 16 09:57:34 garaz-volumio volumio[2676]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 16 09:57:34 garaz-volumio volumio[2676]: Dload Upload Total Spent Left Speed Jul 16 09:57:34 garaz-volumio volumio[2676]: [2.2K blob data] Jul 16 09:57:34 garaz-volumio volumio[2676]: retrying in 5 seconds, trial 0 Jul 16 09:57:34 garaz-volumio volumio[2676]: info: Volumio Calling Home Jul 16 09:57:44 garaz-volumio volumio[2676]: verbose: ControllerMpd::sendMpdCommand add "https://stream.bauermedia.sk/europa2.mp3" Jul 16 09:57:44 garaz-volumio volumio[2676]: error: MPD error: Error: read ECONNRESET Jul 16 09:57:44 garaz-volumio systemd[1]: mpd.service: Succeeded. Jul 16 09:57:44 garaz-volumio systemd[1]: Stopped Music Player Daemon. Jul 16 09:57:44 garaz-volumio systemd[1]: Starting Music Player Daemon... Jul 16 09:57:44 garaz-volumio sudo[3050]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 16 09:57:44 garaz-volumio sudo[3050]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 09:57:44 garaz-volumio sudo[3050]: pam_unix(sudo:session): session closed for user root Jul 16 09:57:46 garaz-volumio mpd[3052]: Jul 16 09:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 16 09:57:46 garaz-volumio systemd[1]: Started Music Player Daemon. Jul 16 09:57:46 garaz-volumio mpd_monitor.sh[503]: MPD Monitor Service: MPD restarted due to no mpc output. Jul 16 09:57:49 garaz-volumio volumio[2676]: error: updateQueue error: null Jul 16 09:57:49 garaz-volumio ntpd[682]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jul 16 09:57:50 garaz-volumio volumio[2676]: info: Discovery: adding c72f228d-a1b0-405d-aa53-37736fea7251 Jul 16 09:57:50 garaz-volumio volumio[2676]: info: Discovery: Found device obyvacka-volumio Jul 16 09:57:50 garaz-volumio volumio[2676]: info: Discovery: Connecting to remote: 192.168.100.120 Jul 16 09:57:51 garaz-volumio volumio[2676]: info: Discovery: adding 61c94b53-f720-4c34-be67-0f6ba4676c48 Jul 16 09:57:51 garaz-volumio volumio[2676]: info: Discovery: Found device garaz-volumio Jul 16 09:57:51 garaz-volumio volumio[2676]: info: CoreCommandRouter::volumioGetState Jul 16 09:57:51 garaz-volumio volumio[2676]: info: CorePlayQueue::getTrack 0 Jul 16 09:57:56 garaz-volumio go-librespot[3023]: time="2025-07-16T09:57:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 16 09:57:56 garaz-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 16 09:57:56 garaz-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 16 09:57:59 garaz-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 16 09:57:59 garaz-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jul 16 09:57:59 garaz-volumio systemd[1]: Stopped go-librespot Daemon. Jul 16 09:57:59 garaz-volumio systemd[1]: Started go-librespot Daemon. Jul 16 09:57:59 garaz-volumio go-librespot[3125]: Librespot-go daemon starting... Jul 16 09:57:59 garaz-volumio go-librespot[3125]: time="2025-07-16T09:57:59+02:00" level=info msg="generated new device id: 2e82e117e7d154e02bc18e9d7067b1a4847705c5" Jul 16 09:57:59 garaz-volumio go-librespot[3125]: time="2025-07-16T09:57:59+02:00" level=debug msg="stored credentials found for 31ykrfcoejvq3eri6uosxaghgvou" Jul 16 09:58:04 garaz-volumio volumio[2676]: info: Discovery: A device disappeared from network Jul 16 09:58:04 garaz-volumio volumio[2676]: info: Discovery: Device obyvacka-volumio disappeared from network Jul 16 09:58:12 garaz-volumio volumio[2676]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.819&uuid=70c06b48de3d14bcf18d3b7865feb41e" http://updates.volumio.org/downloader-v1/track-device Jul 16 09:58:12 garaz-volumio volumio[2676]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 16 09:58:12 garaz-volumio volumio[2676]: Dload Upload Total Spent Left Speed Jul 16 09:58:12 garaz-volumio volumio[2676]: [2.2K blob data] Jul 16 09:58:12 garaz-volumio volumio[2676]: retrying in 5 seconds, trial 1 Jul 16 09:58:12 garaz-volumio volumio[2676]: info: Volumio Calling Home Jul 16 09:58:17 garaz-volumio ntpd[682]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jul 16 09:58:18 garaz-volumio volumio[2676]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Jul 16 09:58:18 garaz-volumio volumio[2676]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jul 16 09:58:19 garaz-volumio volumio[2676]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 09:58:19 garaz-volumio volumio[2676]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Jul 16 09:58:19 garaz-volumio volumio[2676]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jul 16 09:58:19 garaz-volumio volumio[2676]: errno: -3007, Jul 16 09:58:19 garaz-volumio volumio[2676]: code: 'ENOTFOUND', Jul 16 09:58:19 garaz-volumio volumio[2676]: syscall: 'getaddrinfo', Jul 16 09:58:19 garaz-volumio volumio[2676]: hostname: 'ws.audioscrobbler.com' Jul 16 09:58:19 garaz-volumio volumio[2676]: } Jul 16 09:58:19 garaz-volumio volumio[2676]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 09:58:20 garaz-volumio sudo[3177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-16 09:57 Jul 16 09:58:20 garaz-volumio sudo[3177]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:07:25 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3b9115b1943141a9d7186aa434f8f3c2"