Apr 14 22:20:00 volumio-r2r volumio[1138]: info: VolumeController:: Volume=0 Mute =false Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::updateTrackBlock Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrackBlock Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 1 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Reloading queue from file Apr 14 22:20:00 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 1 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::setRepeat null single undefined Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::setRandom null Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio-remote-updater[1106]: [2026-04-14 22:20:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776194399 101 Apr 14 22:20:00 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Setting Device type: Raspberry PI Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Completed loading Core Plugins Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Preparing to generate the ALSA configuration file Apr 14 22:20:00 volumio-r2r volumio[1138]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 22:20:00 volumio-r2r volumio[1138]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 22:20:00 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: VolumeController:: Volume=0 Mute =false Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Discovery: adding 2bff6875-b240-455b-9d78-3357f59a9e23 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Discovery: Found device Volumio_R2R Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Apr 14 22:20:00 volumio-r2r volumio[1138]: ---------------------------- Client requests Volumio play Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPlay Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::play index undefined Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::startPlaybackTimer Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: error: API:pushError: TypeError: Cannot read properties of undefined (reading 'rparadise') Apr 14 22:20:00 volumio-r2r systemd[1]: volumio-autoplay.service: Deactivated successfully. Apr 14 22:20:00 volumio-r2r systemd[1]: Finished volumio-autoplay.service - Volumio autoplay tick. Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Asound.conf file written Apr 14 22:20:00 volumio-r2r sudo[1617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 14 22:20:00 volumio-r2r sudo[1617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r sudo[1617]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r volumio[1138]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Output device has changed, restarting MPD Apr 14 22:20:00 volumio-r2r volumio[1138]: info: ___________ START PLUGINS ___________ Apr 14 22:20:00 volumio-r2r volumio[1138]: info: ControllerMpd::onStart: Initializing MPD Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Creating MPD Configuration file Apr 14 22:20:00 volumio-r2r sudo[1628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 22:20:00 volumio-r2r sudo[1630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 22:20:00 volumio-r2r sudo[1630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [1776194400145] CoreMusicLibrary::Adding element Last_100 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 22:20:00 volumio-r2r sudo[1628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r sudo[1633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 22:20:00 volumio-r2r sudo[1633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [1776194400148] CoreMusicLibrary::Adding element Webradio Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 22:20:00 volumio-r2r sudo[1628]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r sudo[1633]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Initializing BBC Radios Apr 14 22:20:00 volumio-r2r sudo[1636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 22:20:00 volumio-r2r sudo[1636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [1776194400173] CoreMusicLibrary::Adding element Radio Paradise (RP2) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source Radio Paradise (RP2) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Creating Spotify config file Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 22:20:00 volumio-r2r systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 22:20:00 volumio-r2r systemd[1]: mpd.service: Deactivated successfully. Apr 14 22:20:00 volumio-r2r systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 22:20:00 volumio-r2r systemd[1]: mpd.socket: Deactivated successfully. Apr 14 22:20:00 volumio-r2r systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 22:20:00 volumio-r2r systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 22:20:00 volumio-r2r systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 22:20:00 volumio-r2r systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 22:20:00 volumio-r2r sudo[1659]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 22:20:00 volumio-r2r sudo[1659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 22:20:00 volumio-r2r sudo[1662]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 14 22:20:00 volumio-r2r sudo[1659]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [now-playing] ConfigUpdater: config is up to date. Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [1776194400251] CoreMusicLibrary::Adding element 80s80s Radio Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source Radio Paradise (RP2) Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source 80s80s Radio Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [1776194400252] CoreMusicLibrary::Adding element Mother Earth Radio Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source Radio Paradise (RP2) Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source 80s80s Radio Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source Mother Earth Radio Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [MER] Plugin started (SSE mode) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [1776194400254] CoreMusicLibrary::Adding element Radio Paradise Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source Radio Paradise (RP2) Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source 80s80s Radio Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source Mother Earth Radio Apr 14 22:20:00 volumio-r2r volumio[1138]: Cannot find translation for source Radio Paradise Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Starting Raspberry Pi EEPROM Configuration Manager Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Detected full model string: Raspberry Pi 5 Model B Rev 1.0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Matched to capability profile: Raspberry Pi 5 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Detected model: Raspberry Pi 5 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Boot modes: sd, usb, nvme Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Using rpi-eeprom-config at: /usr/bin/rpi-eeprom-config Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Backup directory ensured: /data/configuration/system_controller/rpi_eeprom_config/backup Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RpiEepromConfig] Plugin started successfully Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Loading i18n strings for locale tr Apr 14 22:20:00 volumio-r2r volumio[1138]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Volumio Calling Home Apr 14 22:20:00 volumio-r2r sudo[1667]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Apr 14 22:20:00 volumio-r2r sudo[1667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r sudo[1667]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r sudo[1675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Apr 14 22:20:00 volumio-r2r sudo[1675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r sudo[1672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Apr 14 22:20:00 volumio-r2r sudo[1672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [now-playing] App is listening on port 4004. Apr 14 22:20:00 volumio-r2r sudo[1677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Apr 14 22:20:00 volumio-r2r volumio[1138]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Apr 14 22:20:00 volumio-r2r sudo[1677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Apr 14 22:20:00 volumio-r2r volumio[1138]: info: touch_display: No backlight interface detected. Apr 14 22:20:00 volumio-r2r volumio[1138]: info: MPD Permissions set Apr 14 22:20:00 volumio-r2r volumio[1138]: info: MPD Permissions set Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Spotify config file written Apr 14 22:20:00 volumio-r2r systemd[1]: Starting volumio-autoplay.service - Volumio autoplay tick... Apr 14 22:20:00 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: No need to fix Spotify hosts Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r systemd[1]: Reloading. Apr 14 22:20:00 volumio-r2r sudo[1688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 22:20:00 volumio-r2r sudo[1688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r sudo[1684]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Apr 14 22:20:00 volumio-r2r sudo[1684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r sudo[1684]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:00 volumio-r2r volumio[1138]: info: touch_display: IframeKeyboardBridge extension installed successfully Apr 14 22:20:00 volumio-r2r volumio[1138]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Apr 14 22:20:00 volumio-r2r sudo[1706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Apr 14 22:20:00 volumio-r2r sudo[1706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r sudo[1706]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r sudo[1710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Apr 14 22:20:00 volumio-r2r sudo[1710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r sudo[1710]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r volumio[1138]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Apr 14 22:20:00 volumio-r2r volumio[1138]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Apr 14 22:20:00 volumio-r2r volumio[1138]: info: Apr 14 22:20:00 volumio-r2r volumio[1138]: ---------------------------- Client requests Volumio play Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPlay Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::play index undefined Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreStateMachine::startPlaybackTimer Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r volumio[1138]: info: [RadioParadise] Matched station: Radio Paradise Main Mix (FLAC), chan=0 Apr 14 22:20:00 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 22:20:00 volumio-r2r volumio[1138]: error: API:pushError: TypeError: Cannot read properties of undefined (reading 'then') Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:00 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:00 volumio-r2r systemd[1]: /etc/systemd/system/volumio.service.d/override.conf:6: Invalid environment assignment, ignoring: --trace-warnings Apr 14 22:20:00 volumio-r2r sudo[1677]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:00 volumio-r2r systemd[1]: volumio-autoplay.service: Deactivated successfully. Apr 14 22:20:00 volumio-r2r systemd[1]: Finished volumio-autoplay.service - Volumio autoplay tick. Apr 14 22:20:00 volumio-r2r volumio[1138]: info: touch_display: systemctl daemon-reload succeeded. Apr 14 22:20:00 volumio-r2r sudo[1740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Apr 14 22:20:00 volumio-r2r sudo[1740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:00 volumio-r2r systemd[1]: Reloading. Apr 14 22:20:00 volumio-r2r systemd[1]: /etc/systemd/system/volumio.service.d/override.conf:6: Invalid environment assignment, ignoring: --trace-warnings Apr 14 22:20:01 volumio-r2r bash[1228]: setdatetime-helper: all HTTPS Date fallbacks failed Apr 14 22:20:01 volumio-r2r systemd[1]: setdatetime-helper.service: Deactivated successfully. Apr 14 22:20:01 volumio-r2r systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Apr 14 22:20:01 volumio-r2r sudo[1675]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: systemctl disable getty@tty1.service succeeded. Apr 14 22:20:01 volumio-r2r systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:01 volumio-r2r systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:01 volumio-r2r systemd[1]: Reached target multi-user.target - Multi-User System. Apr 14 22:20:01 volumio-r2r systemd[1]: Reached target graphical.target - Graphical Interface. Apr 14 22:20:01 volumio-r2r (ly-image)[1765]: bootlogo-clear.service: Failed to locate executable /usr/bin/ply-image: No such file or directory Apr 14 22:20:01 volumio-r2r (ly-image)[1765]: bootlogo-clear.service: Failed at step EXEC spawning /usr/bin/ply-image: No such file or directory Apr 14 22:20:01 volumio-r2r systemd[1]: Starting bootlogo-clear.service - Clear boot logo... Apr 14 22:20:01 volumio-r2r systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 22:20:01 volumio-r2r go-librespot[1767]: go-librespot daemon starting... Apr 14 22:20:01 volumio-r2r sudo[1688]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:01 volumio-r2r systemd[1]: Started standby-gpio.service - Standby GPIO daemon (STM32 OFF -> RPi standby). Apr 14 22:20:01 volumio-r2r systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Apr 14 22:20:01 volumio-r2r systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Apr 14 22:20:01 volumio-r2r sudo[1740]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:01 volumio-r2r systemd[1]: bootlogo-clear.service: Main process exited, code=exited, status=203/EXEC Apr 14 22:20:01 volumio-r2r systemd[1]: bootlogo-clear.service: Failed with result 'exit-code'. Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: Volumio Kiosk started. Apr 14 22:20:01 volumio-r2r systemd[1]: Failed to start bootlogo-clear.service - Clear boot logo. Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:01 volumio-r2r sudo[1672]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: systemctl stop getty@tty1.service succeeded. Apr 14 22:20:01 volumio-r2r systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: X display number found: Apr 14 22:20:01 volumio-r2r systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Apr 14 22:20:01 volumio-r2r go-librespot[1768]: time="2026-04-14T22:20:01+03:00" level=info msg="running go-librespot 0.7.1" Apr 14 22:20:01 volumio-r2r go-librespot[1768]: time="2026-04-14T22:20:01+03:00" level=debug msg="app state loaded" Apr 14 22:20:01 volumio-r2r go-librespot[1768]: time="2026-04-14T22:20:01+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 22:20:01 volumio-r2r go-librespot[1768]: time="2026-04-14T22:20:01+03: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" Apr 14 22:20:01 volumio-r2r systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 22:20:01 volumio-r2r systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 22:20:01 volumio-r2r startx[1800]: X.Org X Server 1.21.1.7 Apr 14 22:20:01 volumio-r2r startx[1800]: X Protocol Version 11, Revision 0 Apr 14 22:20:01 volumio-r2r startx[1800]: Current Operating System: Linux volumio-r2r 6.12.47-v8+ #1904 SMP PREEMPT Mon Sep 15 13:10:52 BST 2025 aarch64 Apr 14 22:20:01 volumio-r2r startx[1800]: Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe cgroup_disable=memory numa_policy=interleave nvme.max_host_mem_size_mb=0 numa=fake=8 system_heap.max_order=0 iommu_dma_numa_policy=interleave smsc95xx.macaddr=D8:3A:DD:8D:CD:DB vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000 dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA10,115200 imgpart=UUID=b0b466fc-4556-43af-9f97-ebe56fe4abe4 imgfile=/volumio_current.sqsh bootpart=UUID=0428-C7E4 datapart=UUID=82051e0e-a859-4f54-aa9f-0cc23a932af8 uuidconfig=cmdline.txt rootwait bootdelay=0 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no systemd.show_status=false rd.systemd.show_status=false Apr 14 22:20:01 volumio-r2r startx[1800]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Apr 14 22:20:01 volumio-r2r startx[1800]: Current version of pixman: 0.44.0 Apr 14 22:20:01 volumio-r2r startx[1800]: Before reporting problems, check http://wiki.x.org Apr 14 22:20:01 volumio-r2r startx[1800]: to make sure that you have the latest version. Apr 14 22:20:01 volumio-r2r startx[1800]: Markers: (--) probed, (**) from config file, (==) default setting, Apr 14 22:20:01 volumio-r2r startx[1800]: (++) from command line, (!!) notice, (II) informational, Apr 14 22:20:01 volumio-r2r startx[1800]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Apr 14 22:20:01 volumio-r2r startx[1800]: (==) Log file: "/var/log/Xorg.0.log", Time: Tue Apr 14 22:20:01 2026 Apr 14 22:20:01 volumio-r2r startx[1800]: (==) Using config directory: "/etc/X11/xorg.conf.d" Apr 14 22:20:01 volumio-r2r startx[1800]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Apr 14 22:20:01 volumio-r2r systemd[1]: Starting volumio-autoplay.service - Volumio autoplay tick... Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: X display number found: 0 Apr 14 22:20:01 volumio-r2r volumio[1138]: info: Apr 14 22:20:01 volumio-r2r volumio[1138]: ---------------------------- Client requests Volumio play Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPlay Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CoreStateMachine::play index undefined Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CoreStateMachine::startPlaybackTimer Apr 14 22:20:01 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:01 volumio-r2r volumio[1138]: info: [RadioParadise] Matched station: Radio Paradise Main Mix (FLAC), chan=0 Apr 14 22:20:01 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 22:20:01 volumio-r2r volumio[1138]: error: API:pushError: TypeError: Cannot read properties of undefined (reading 'then') Apr 14 22:20:01 volumio-r2r systemd[1]: volumio-autoplay.service: Deactivated successfully. Apr 14 22:20:01 volumio-r2r systemd[1]: Finished volumio-autoplay.service - Volumio autoplay tick. Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 14 22:20:01 volumio-r2r volumio[1138]: info: touch_display: X display number found: 0 Apr 14 22:20:01 volumio-r2r mpd[1663]: 2026-04-14T22:20:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 22:20:01 volumio-r2r systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 22:20:01 volumio-r2r sudo[1630]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:01 volumio-r2r systemd[1]: Startup finished in 4.226s (kernel) + 9.472s (userspace) = 13.698s. Apr 14 22:20:01 volumio-r2r sudo[1636]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:01 volumio-r2r volumio[1138]: info: Completed starting Core Plugins Apr 14 22:20:01 volumio-r2r volumio[1138]: info: ------------------------------------------- Apr 14 22:20:01 volumio-r2r volumio[1138]: info: ----- MyVolumio plugins startup ---- Apr 14 22:20:01 volumio-r2r volumio[1138]: info: ------------------------------------------- Apr 14 22:20:01 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 22:20:01 volumio-r2r volumio[1138]: info: MPD running with PID1663 Apr 14 22:20:01 volumio-r2r volumio[1138]: ,establishing connection Apr 14 22:20:01 volumio-r2r volumio[1138]: error: MPD error: The expression evaluated to a falsy value: Apr 14 22:20:01 volumio-r2r volumio[1138]: assert.ok(self.idling) Apr 14 22:20:01 volumio-r2r volumio[1138]: error: The expression evaluated to a falsy value: Apr 14 22:20:01 volumio-r2r volumio[1138]: assert.ok(self.idling) Apr 14 22:20:01 volumio-r2r volumio[1138]: error: MPD error: The expression evaluated to a falsy value: Apr 14 22:20:01 volumio-r2r volumio[1138]: assert.ok(self.idling) Apr 14 22:20:01 volumio-r2r volumio[1138]: error: The expression evaluated to a falsy value: Apr 14 22:20:01 volumio-r2r volumio[1138]: assert.ok(self.idling) Apr 14 22:20:01 volumio-r2r volumio[1138]: error: updateQueue error: null Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: touch_display: Setting screensaver timeout to 0 seconds. Apr 14 22:20:02 volumio-r2r dhcpcd[1172]: eth0: using static address 192.168.1.21/24 Apr 14 22:20:02 volumio-r2r avahi-daemon[1089]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.21. Apr 14 22:20:02 volumio-r2r avahi-daemon[1089]: New relevant interface eth0.IPv4 for mDNS. Apr 14 22:20:02 volumio-r2r avahi-daemon[1089]: Registering new address record for 192.168.1.21 on eth0.IPv4. Apr 14 22:20:02 volumio-r2r dhcpcd[1172]: eth0: adding route to 192.168.1.0/24 Apr 14 22:20:02 volumio-r2r dhcpcd[1172]: eth0: adding default route via 192.168.1.1 Apr 14 22:20:02 volumio-r2r systemd[1]: Starting volumio-autoplay.service - Volumio autoplay tick... Apr 14 22:20:02 volumio-r2r systemd[1]: welcome.service: Deactivated successfully. Apr 14 22:20:02 volumio-r2r systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 14 22:20:02 volumio-r2r systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 14 22:20:02 volumio-r2r systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 14 22:20:02 volumio-r2r welcome[1928]: Resolved ip:[1] 192.168.1.21 Apr 14 22:20:02 volumio-r2r systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- Client requests Volumio play Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPlay Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreStateMachine::play index undefined Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreStateMachine::startPlaybackTimer Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: [RadioParadise] Matched station: Radio Paradise Main Mix (FLAC), chan=0 Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand stop took 1 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand clear Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand clear took 1 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand consume 1 Apr 14 22:20:02 volumio-r2r systemd[1]: volumio-autoplay.service: Deactivated successfully. Apr 14 22:20:02 volumio-r2r systemd[1]: Finished volumio-autoplay.service - Volumio autoplay tick. Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:02 volumio-r2r volumio[1138]: error: updateQueue error: null Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: options Apr 14 22:20:02 volumio-r2r volumio[1138]: error: updateQueue error: null Apr 14 22:20:02 volumio-r2r volumio[1138]: error: updateQueue error: null Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 3ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand consume 1 took 2 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 2ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 1ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: [1776194402921] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/flacm Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/flacm" Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: options Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: options Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand status took 5 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 9ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand add "https://stream.radioparadise.com/flacm" took 9 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand status took 8 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand status took 8 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand play Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:02 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:20:02 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 15ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 15ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Apr 14 22:20:02 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 11ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: sendMpdCommand play took 10 milliseconds Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 4ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: ------------------------------ 4ms Apr 14 22:20:02 volumio-r2r volumio[1138]: info: [RadioParadise] Using metadata URL: https://api.radioparadise.com/api/now_playing?chan=0 Apr 14 22:20:02 volumio-r2r volumio[1138]: info: [1776194402941] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 31 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 32 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 31 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 33ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 2 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 35ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 34ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 5ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 3ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 3ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: [1776194403813] [RadioParadise] received new metadata: {"time":118,"artist":"Norah Jones","title":"Light as a Feather","album":"The Fall","year":"2009","cover":"https://img.radioparadise.com/covers/l/11034.jpg","cover_med":"https://img.radioparadise.com/covers/m/11034.jpg","cover_small":"https://img.radioparadise.com/covers/s/11034.jpg"} Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/11034.jpg","uri":"https://stream.radioparadise.com/flacm","name":"Light as a Feather","title":"Light as a Feather","artist":"Norah Jones","album":"The Fall","streaming":true,"disableUiControls":true,"duration":123,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: CURRENT POSITION 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreStateMachine::syncState stateService play Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreStateMachine::syncState currentStatus stop Apr 14 22:20:03 volumio-r2r volumio[1138]: info: [1776194403815] [RadioParadise] setting new timer with duration of 123000 seconds. Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Discovery: this is already registered, 2bff6875-b240-455b-9d78-3357f59a9e23 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Discovery: Found device Volumio_R2R Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 1 Apr 14 22:20:03 volumio-r2r systemd[1]: Starting volumio-autoplay.service - Volumio autoplay tick... Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Apr 14 22:20:03 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 2ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 2ms Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 1ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 3ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:03 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:03 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 4ms Apr 14 22:20:03 volumio-r2r volumio[1138]: info: ------------------------------ 3ms Apr 14 22:20:04 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:04 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:04 volumio-r2r systemd[1]: volumio-autoplay.timer: Deactivated successfully. Apr 14 22:20:04 volumio-r2r systemd[1]: Stopped volumio-autoplay.timer - Volumio autoplay timer. Apr 14 22:20:04 volumio-r2r systemd[1]: volumio-autoplay.service: Deactivated successfully. Apr 14 22:20:04 volumio-r2r systemd[1]: Finished volumio-autoplay.service - Volumio autoplay tick. Apr 14 22:20:04 volumio-r2r volumio[1138]: info: go-librespot daemon successfully initialized Apr 14 22:20:04 volumio-r2r ntpd[1258]: IO: Listen normally on 3 eth0 192.168.1.21:123 Apr 14 22:20:04 volumio-r2r ntpd[1258]: IO: new interface(s) found: waking up resolver Apr 14 22:20:04 volumio-r2r ntpd[1258]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 22:20:04 volumio-r2r dbus-daemon[1090]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.14' (uid=1000 pid=1953 comm="/usr/lib/chromium/chromium --force-renderer-access") Apr 14 22:20:04 volumio-r2r dbus-daemon[1090]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service not found. Apr 14 22:20:04 volumio-r2r ntpd[1258]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Apr 14 22:20:04 volumio-r2r ntpd[1258]: DNS: Pool taking: 185.226.92.106 Apr 14 22:20:04 volumio-r2r ntpd[1258]: DNS: Pool taking: 89.252.135.27 Apr 14 22:20:04 volumio-r2r ntpd[1258]: DNS: Pool taking: 85.199.214.98 Apr 14 22:20:04 volumio-r2r ntpd[1258]: DNS: Pool taking: 176.235.250.150 Apr 14 22:20:04 volumio-r2r ntpd[1258]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Apr 14 22:20:04 volumio-r2r systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 14 22:20:04 volumio-r2r systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 22:20:04 volumio-r2r systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 22:20:04 volumio-r2r go-librespot[2054]: go-librespot daemon starting... Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=info msg="running go-librespot 0.7.1" Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=debug msg="app state loaded" Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=info msg="zeroconf server listening on port 41393" Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 22:20:04 volumio-r2r dbus-daemon[1090]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service' requested by ':1.14' (uid=1000 pid=1953 comm="/usr/lib/chromium/chromium --force-renderer-access") Apr 14 22:20:04 volumio-r2r systemd[1]: Starting upower.service - Daemon for power management... Apr 14 22:20:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:04+03:00" level=debug msg="obtained new client token: AACeJFv08pxDTRLDmRS5Eyz6aUDwJMlW/z/rdanijEXLgrToKxNCXT1FLjUbZbrmjWoelhmJU1Co5I/VRr2KuG8Gtsevl4TdLS2T1WOeogtkCb68dKhS9meU1XYOInimQHr0jq91GmgS2Hd95w8UKWavHiSacbWOMZmk03aHVaDOIpIkajTIdIDNJPrHcxcyDNkh2LoyjbYyv+vdoxOIc2BmKcckG9ScZK6+HuL8PoWCodQ3/43Ahf9+lg==" Apr 14 22:20:04 volumio-r2r dbus-daemon[1090]: [system] Successfully activated service 'org.freedesktop.UPower' Apr 14 22:20:04 volumio-r2r systemd[1]: Started upower.service - Daemon for power management. Apr 14 22:20:04 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to 192.168.1.21 from 192.168.1.16 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetQueue Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CoreStateMachine::getQueue Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CorePlayQueue::getQueue Apr 14 22:20:05 volumio-r2r volumio[1138]: info: Listing playlists Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 14 22:20:05 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: websocket Total Clients: 6 Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="completed keyexchange" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="completed challenge" Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:05 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=info msg="authenticated AP" username="mp*****on" Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 62.12.173.11 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 161.9.149.67 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 162.159.200.123 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 178.79.155.116 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 2606:4700:f1::1 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 2606:4700:f1::123 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 2a05:dfc1:700:2:21f::123 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: Pool taking: 2a03:2100:0:2c::82:2 Apr 14 22:20:05 volumio-r2r ntpd[1258]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=info msg="authenticated Login5" username="mp*****on" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="initializing zeroconf session" username="mp*****on" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="dealer connection opened" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=trace msg="starting accesspoint recv loop" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=trace msg="starting dealer recv loop" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=trace msg="received accesspoint ping" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="received connection id: NDQzZDc3ZWQtNTM5...NTQ4M0U3RjFGNQ==" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=trace msg="received accesspoint pong ack" Apr 14 22:20:05 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:05+03:00" level=debug msg="put connect state because NEW_DEVICE" Apr 14 22:20:06 volumio-r2r ntpd[1258]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 22:20:06 volumio-r2r ntpd[1258]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Apr 14 22:20:06 volumio-r2r ntpd[1258]: DNS: Pool taking: 212.154.83.90 Apr 14 22:20:06 volumio-r2r ntpd[1258]: DNS: Pool taking: 62.12.173.12 Apr 14 22:20:06 volumio-r2r ntpd[1258]: DNS: Pool taking: 37.187.145.181 Apr 14 22:20:06 volumio-r2r ntpd[1258]: DNS: Pool taking: 93.115.79.15 Apr 14 22:20:06 volumio-r2r ntpd[1258]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Apr 14 22:20:06 volumio-r2r volumio[1138]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 14 22:20:07 volumio-r2r volumio[1138]: info: Initializing connection to go-librespot Websocket Apr 14 22:20:07 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:07+03:00" level=debug msg="new websocket client" Apr 14 22:20:07 volumio-r2r volumio[1138]: info: Connection to go-librespot Websocket established Apr 14 22:20:07 volumio-r2r ntpd[1258]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Apr 14 22:20:07 volumio-r2r ntpd[1258]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Apr 14 22:20:07 volumio-r2r ntpd[1258]: DNS: Pool taking: 192.36.143.130 Apr 14 22:20:07 volumio-r2r ntpd[1258]: DNS: Pool taking: 194.27.156.207 Apr 14 22:20:07 volumio-r2r ntpd[1258]: DNS: Pool taking: 185.255.95.207 Apr 14 22:20:07 volumio-r2r ntpd[1258]: DNS: Pool taking: 162.159.200.1 Apr 14 22:20:07 volumio-r2r ntpd[1258]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Apr 14 22:20:07 volumio-r2r volumio[1138]: info: Volumio Network Manager: Network status updated: 1 Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Apr 14 22:20:08 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Apr 14 22:20:08 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Apr 14 22:20:08 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Apr 14 22:20:08 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Apr 14 22:20:08 volumio-r2r volumio[1138]: ---------------------------- MPD announces system playlist update Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Ignoring MPD Status Update Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Apr 14 22:20:08 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ControllerMpd::getState Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand status Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ------------------------------ 2ms Apr 14 22:20:08 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ------------------------------ 1ms Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:08 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ------------------------------ 1ms Apr 14 22:20:08 volumio-r2r volumio[1138]: info: sendMpdCommand status took 1 milliseconds Apr 14 22:20:08 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseState Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:08 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:08 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ------------------------------ 3ms Apr 14 22:20:08 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 14 22:20:08 volumio-r2r volumio[1138]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:08 volumio-r2r volumio[1138]: verbose: ControllerMpd::parseTrackInfo Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:08 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:08 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ControllerMpd::pushState Apr 14 22:20:08 volumio-r2r volumio[1138]: info: CoreCommandRouter::servicePushState Apr 14 22:20:08 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ------------------------------ 4ms Apr 14 22:20:08 volumio-r2r volumio[1138]: info: ------------------------------ 3ms Apr 14 22:20:09 volumio-r2r volumio[1138]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 14 22:20:09 volumio-r2r volumio[1138]: info: CoreCommandRouter::Close All Modals sent Apr 14 22:20:10 volumio-r2r systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Apr 14 22:20:10 volumio-r2r systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:10 volumio-r2r systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:10 volumio-r2r upmpdcli[2202]: Could not open config: /tmp/upmpdcli.conf Apr 14 22:20:10 volumio-r2r systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 14 22:20:10 volumio-r2r systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 14 22:20:10 volumio-r2r volumio[1138]: info: Getting Spotify volume Apr 14 22:20:10 volumio-r2r volumio[1138]: info: Spotify volume: 100 Apr 14 22:20:10 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 14 22:20:10 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:10 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:08 volumio-r2r ntpd[1258]: CLOCK: time stepped by -1.366978 Apr 14 22:20:08 volumio-r2r systemd-journald[534]: Time jumped backwards, rotating. Apr 14 22:20:08 volumio-r2r ntpd[1258]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.084&uuid=9660931adbaf88129ab31c1696cd2f63" http://updates.volumio.org/downloader-v1/track-device Apr 14 22:20:08 volumio-r2r volumio[1138]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 14 22:20:08 volumio-r2r volumio[1138]: Dload Upload Total Spent Left Speed Apr 14 22:20:08 volumio-r2r volumio[1138]: [132B blob data] Apr 14 22:20:08 volumio-r2r volumio[1138]: retrying in 5 seconds, trial 0 Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Volumio Calling Home Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 22:20:08 volumio-r2r volumio[1138]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 22:20:08 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 22:20:09 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 22:20:09 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 22:20:09 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:09 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:09 volumio-r2r volumio[1138]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 22:20:09 volumio-r2r volumio[1138]: info: MyVolumio login type: Token Apr 14 22:20:09 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 22:20:09 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 22:20:09 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 22:20:09 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 22:20:09 volumio-r2r volumio[1138]: info: Streaming services startup Apr 14 22:20:09 volumio-r2r volumio[1138]: info: Starting Streaming Daemon Apr 14 22:20:09 volumio-r2r sudo[2217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 22:20:09 volumio-r2r sudo[2217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:09 volumio-r2r volumio[1138]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 22:20:09 volumio-r2r sudo[2217]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:09 volumio-r2r volumio[1138]: error: Cannot start Volumio Streaming Daemon Apr 14 22:20:09 volumio-r2r volumio[1138]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 22:20:09 volumio-r2r volumio[1138]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 22:20:09 volumio-r2r volumio[1138]: info: Volumio called home Apr 14 22:20:10 volumio-r2r volumio[1138]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 22:20:10 volumio-r2r volumio[1138]: info: MyVolumio token set successfully Apr 14 22:20:10 volumio-r2r volumio[1138]: info: MYVOLUMIO: Adding device Apr 14 22:20:10 volumio-r2r volumio[1138]: info: MYVOLUMIO: Evaluating Server Apr 14 22:20:11 volumio-r2r volumio[1138]: info: MyVolumio status changed Apr 14 22:20:11 volumio-r2r volumio[1138]: info: Streaming services startup Apr 14 22:20:11 volumio-r2r volumio[1138]: info: Starting Streaming Daemon Apr 14 22:20:11 volumio-r2r volumio[1138]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 22:20:11 volumio-r2r volumio[1138]: info: Removing audio output: Apr 14 22:20:11 volumio-r2r volumio[1138]: info: Stoppping Tunnel 1 Apr 14 22:20:11 volumio-r2r sudo[2262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 22:20:11 volumio-r2r sudo[2262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:11 volumio-r2r sudo[2262]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:11 volumio-r2r volumio[1138]: error: Cannot start Volumio Streaming Daemon Apr 14 22:20:11 volumio-r2r volumio[1138]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 22:20:11 volumio-r2r volumio[1138]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 22:20:11 volumio-r2r sudo[2265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 22:20:11 volumio-r2r sudo[2265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 22:20:11 volumio-r2r sudo[2265]: pam_unix(sudo:session): session closed for user root Apr 14 22:20:11 volumio-r2r volumio[1138]: info: Remote SSH Stopped Apr 14 22:20:17 volumio-r2r sshd[2275]: Accepted password for volumio from 192.168.1.16 port 55100 ssh2 Apr 14 22:20:17 volumio-r2r sshd[2275]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Apr 14 22:20:17 volumio-r2r systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Apr 14 22:20:17 volumio-r2r systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Apr 14 22:20:17 volumio-r2r systemd-logind[1101]: New session 1 of user volumio. Apr 14 22:20:17 volumio-r2r systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Apr 14 22:20:17 volumio-r2r systemd[1]: Starting user@1000.service - User Manager for UID 1000... Apr 14 22:20:17 volumio-r2r (systemd)[2371]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Apr 14 22:20:17 volumio-r2r systemd[2371]: Queued start job for default target default.target. Apr 14 22:20:17 volumio-r2r systemd[2371]: Created slice app.slice - User Application Slice. Apr 14 22:20:17 volumio-r2r systemd[2371]: Reached target paths.target - Paths. Apr 14 22:20:17 volumio-r2r systemd[2371]: Reached target timers.target - Timers. Apr 14 22:20:17 volumio-r2r systemd[2371]: Starting dbus.socket - D-Bus User Message Bus Socket... Apr 14 22:20:17 volumio-r2r systemd[2371]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Apr 14 22:20:17 volumio-r2r systemd[2371]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Apr 14 22:20:17 volumio-r2r systemd[2371]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Apr 14 22:20:17 volumio-r2r systemd[2371]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Apr 14 22:20:17 volumio-r2r systemd[2371]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Apr 14 22:20:17 volumio-r2r systemd[2371]: Listening on dbus.socket - D-Bus User Message Bus Socket. Apr 14 22:20:17 volumio-r2r systemd[2371]: Reached target sockets.target - Sockets. Apr 14 22:20:17 volumio-r2r systemd[2371]: Reached target basic.target - Basic System. Apr 14 22:20:17 volumio-r2r systemd[1]: Started user@1000.service - User Manager for UID 1000. Apr 14 22:20:17 volumio-r2r systemd[2371]: Started mpris-proxy.service - Bluetooth mpris proxy. Apr 14 22:20:17 volumio-r2r systemd[2371]: Reached target default.target - Main User Target. Apr 14 22:20:17 volumio-r2r systemd[2371]: Startup finished in 222ms. Apr 14 22:20:17 volumio-r2r systemd[1]: Started session-1.scope - Session 1 of User volumio. Apr 14 22:20:17 volumio-r2r systemd[2371]: Created slice session.slice - User Core Session Slice. Apr 14 22:20:17 volumio-r2r systemd[2371]: Starting dbus.service - D-Bus User Message Bus... Apr 14 22:20:17 volumio-r2r systemd[2371]: Started dbus.service - D-Bus User Message Bus. Apr 14 22:20:17 volumio-r2r sshd[2275]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 14 22:20:19 volumio-r2r volumio[1138]: info: Setting Geolocation for MyVolumio to eu4 Apr 14 22:20:19 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:19 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:19 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:20 volumio-r2r volumio[1138]: info: Successfully Added MyVolumio device Apr 14 22:20:20 volumio-r2r volumio[1138]: info: Updating MyVolumio device info Apr 14 22:20:20 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:20 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:20 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:20 volumio-r2r volumio[1138]: info: Successfully Updated MyVolumio device Apr 14 22:20:21 volumio-r2r systemd[1]: systemd-fsckd.service: Deactivated successfully. Apr 14 22:20:24 volumio-r2r systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Apr 14 22:20:24 volumio-r2r systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:24 volumio-r2r systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:24 volumio-r2r upmpdcli[2489]: Could not open config: /tmp/upmpdcli.conf Apr 14 22:20:24 volumio-r2r systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 14 22:20:24 volumio-r2r systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 14 22:20:24 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 22:20:24 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 14 22:20:24 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetState Apr 14 22:20:24 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:20:28 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 22:20:28 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:28 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 22:20:29 volumio-r2r volumio-remote-updater[1106]: Test mode disabled Apr 14 22:20:29 volumio-r2r volumio-remote-updater[1106]: Alpha mode disabled Apr 14 22:20:29 volumio-r2r volumio-remote-updater[1106]: Alpha legacy test mode disabled Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 14 22:20:29 volumio-r2r volumio[1138]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

NEW ADDITIONS

","title":"Update v4.119","updateavailable":true} Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioGetBrowseSources Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 22:20:29 volumio-r2r volumio[1138]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 14 22:20:29 volumio-r2r volumio[1138]: info: Completed starting MyVolumio Plugin Apr 14 22:20:29 volumio-r2r volumio[1138]: [Metrics] CommandRouter: 34s 132.92ms Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumiosetStartupVolume Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::Close All Modals sent Apr 14 22:20:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::Close All Modals sent Apr 14 22:20:30 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 14 22:20:30 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 14 22:20:30 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 14 22:20:34 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:34+03:00" level=trace msg="sent dealer ping" Apr 14 22:20:34 volumio-r2r go-librespot[2064]: time="2026-04-14T22:20:34+03:00" level=trace msg="received dealer pong" Apr 14 22:20:36 volumio-r2r volumio[1138]: info: BOOT COMPLETED Apr 14 22:20:39 volumio-r2r systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Apr 14 22:20:39 volumio-r2r systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:39 volumio-r2r systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:39 volumio-r2r upmpdcli[2727]: Could not open config: /tmp/upmpdcli.conf Apr 14 22:20:39 volumio-r2r systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 14 22:20:39 volumio-r2r systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 14 22:20:50 volumio-r2r systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Apr 14 22:20:54 volumio-r2r systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Apr 14 22:20:54 volumio-r2r systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:54 volumio-r2r systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:20:54 volumio-r2r upmpdcli[2953]: Could not open config: /tmp/upmpdcli.conf Apr 14 22:20:54 volumio-r2r systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 14 22:20:54 volumio-r2r systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 14 22:20:55 volumio-r2r systemd[1]: setdatetime-helper.service: Deactivated successfully. Apr 14 22:20:55 volumio-r2r systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Apr 14 22:21:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:21:04+03:00" level=trace msg="sent dealer ping" Apr 14 22:21:04 volumio-r2r go-librespot[2064]: time="2026-04-14T22:21:04+03:00" level=trace msg="received dealer pong" Apr 14 22:21:09 volumio-r2r systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5. Apr 14 22:21:09 volumio-r2r systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:21:09 volumio-r2r systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:21:09 volumio-r2r upmpdcli[3201]: Could not open config: /tmp/upmpdcli.conf Apr 14 22:21:09 volumio-r2r systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 14 22:21:09 volumio-r2r systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 14 22:21:24 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 8 Apr 14 22:21:24 volumio-r2r volumio[1138]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 8 Apr 14 22:21:25 volumio-r2r systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 6. Apr 14 22:21:25 volumio-r2r systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:21:25 volumio-r2r systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 14 22:21:25 volumio-r2r upmpdcli[3407]: Could not open config: /tmp/upmpdcli.conf Apr 14 22:21:25 volumio-r2r systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 14 22:21:25 volumio-r2r systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 14 22:21:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 22:21:29 volumio-r2r volumio[1138]: info: CURURI: music-library Apr 14 22:21:29 volumio-r2r volumio[1138]: info: Preload queue cleared Apr 14 22:21:29 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 22:21:29 volumio-r2r volumio[1138]: info: CURURI: music-library/INTERNAL Apr 14 22:21:29 volumio-r2r volumio[1138]: info: Preload queue cleared Apr 14 22:21:30 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 22:21:30 volumio-r2r volumio[1138]: info: CURURI: music-library/INTERNAL/Erdal Apr 14 22:21:30 volumio-r2r volumio[1138]: info: Preload queue cleared Apr 14 22:21:32 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 22:21:32 volumio-r2r volumio[1138]: info: CURURI: music-library/INTERNAL/Erdal/DSDTest Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Preload queue cleared Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Preloading song: music-library/INTERNAL/Erdal/DSDTest/01 - David Elias - The Window - Vision of Her (DSD64).dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Preloading song: music-library/INTERNAL/Erdal/DSDTest/1kHz-0dBFS.dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Preloading song: music-library/INTERNAL/Erdal/DSDTest/Scorpions - Acoustica [88985406981] D4.dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Preloading song: music-library/INTERNAL/Erdal/DSDTest/07 - David Elias - Acoustic Trio - Rodeo On A Ridge (DSD64).dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Preloading song: music-library/INTERNAL/Erdal/DSDTest/08 - David Elias - Crossing - Morning Light Western Town (DSD64 2.0).dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/01 - David Elias - The Window - Vision of Her (DSD64).dsf in service mpd Apr 14 22:21:32 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=David%20Elias//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F01%20-%20David%20Elias%20-%20The%20Window%20-%20Vision%20of%20Her%20(DSD64).dsf&metadata=false Apr 14 22:21:32 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/01 - David Elias - The Window - Vision of Her (DSD64).dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/1kHz-0dBFS.dsf in service mpd Apr 14 22:21:32 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F1kHz-0dBFS.dsf&metadata=false Apr 14 22:21:32 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/1kHz-0dBFS.dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/Scorpions - Acoustica [88985406981] D4.dsf in service mpd Apr 14 22:21:32 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FScorpions%20-%20Acoustica%20%5B88985406981%5D%20D4.dsf&metadata=false Apr 14 22:21:32 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Scorpions - Acoustica [88985406981] D4.dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/07 - David Elias - Acoustic Trio - Rodeo On A Ridge (DSD64).dsf in service mpd Apr 14 22:21:32 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=David%20Elias/Acoustic%20Trio%20-%20DSD%20Sessions/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F07%20-%20David%20Elias%20-%20Acoustic%20Trio%20-%20Rodeo%20On%20A%20Ridge%20(DSD64).dsf&metadata=false Apr 14 22:21:32 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/07 - David Elias - Acoustic Trio - Rodeo On A Ridge (DSD64).dsf Apr 14 22:21:32 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/08 - David Elias - Crossing - Morning Light Western Town (DSD64 2.0).dsf in service mpd Apr 14 22:21:32 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=David%20Elias/Crossing/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F08%20-%20David%20Elias%20-%20Crossing%20-%20Morning%20Light%20Western%20Town%20(DSD64%202.0).dsf&metadata=false Apr 14 22:21:32 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/08 - David Elias - Crossing - Morning Light Western Town (DSD64 2.0).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Preload queue cleared Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::ClearQueue Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::stop Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::stPlaybackTimer Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::updateTrackBlock Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrackBlock Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::pushState Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushState Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::serviceStop Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreCommandRouter::serviceStop Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ControllerMpd::stop Apr 14 22:21:33 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::clearPlayQueue Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::saveQueue Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushQueue Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::addQueueItems Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::addQueueItems Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Preload queue cleared Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/01 - David Elias - The Window - Vision of Her (DSD64).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Using cached record of: music-library/INTERNAL/Erdal/DSDTest/01 - David Elias - The Window - Vision of Her (DSD64).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPushQueue Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::saveQueue Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::updateTrackBlock Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrackBlock Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreCommandRouter::volumioPlay Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::play index 0 Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::addQueueItems Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::addQueueItems Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Preload queue cleared Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/1kHz-0dBFS.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Using cached record of: music-library/INTERNAL/Erdal/DSDTest/1kHz-0dBFS.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/Scorpions - Acoustica [88985406981] D4.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Using cached record of: music-library/INTERNAL/Erdal/DSDTest/Scorpions - Acoustica [88985406981] D4.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/07 - David Elias - Acoustic Trio - Rodeo On A Ridge (DSD64).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Using cached record of: music-library/INTERNAL/Erdal/DSDTest/07 - David Elias - Acoustic Trio - Rodeo On A Ridge (DSD64).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/08 - David Elias - Crossing - Morning Light Western Town (DSD64 2.0).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Using cached record of: music-library/INTERNAL/Erdal/DSDTest/08 - David Elias - Crossing - Morning Light Western Town (DSD64 2.0).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/5 Tracks in DSD512-st Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/5 Tracks in DSD512-st in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/Lipps, Inc. - Mouth To Mouth - 1980,(Holland),DSF(tracks),(CA2ML+NG-6+308+TT-81) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/Lipps, Inc. - Mouth To Mouth - 1980,(Holland),DSF(tracks),(CA2ML+NG-6+308+TT-81) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/Pink Floyd - The Dark Side of the Moon (2016) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/Pink Floyd - The Dark Side of the Moon (2016) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/Pink Floyd - The Wall (2016) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/Pink Floyd - The Wall (2016) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/The Alan Parsons Project - Eye In The Sky - 1982,(Germany),DSF(tracks),(ART-9XA+KIV+SAEC-308+TT-81+K-10R) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/The Alan Parsons Project - Eye In The Sky - 1982,(Germany),DSF(tracks),(ART-9XA+KIV+SAEC-308+TT-81+K-10R) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/The Alan Parsons Project - I Robot (1977- Japan) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/The Alan Parsons Project - I Robot (1977- Japan) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Adding Item to queue: music-library/INTERNAL/Erdal/DSDTest/The Alan Parsons Project - The Turn Of A Friendly Card - 1980,(Germany),DSF(tracks),(ART-9XA+KIV+SAEC-308+TT-81+K-10R) Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Exploding uri music-library/INTERNAL/Erdal/DSDTest/The Alan Parsons Project - The Turn Of A Friendly Card - 1980,(Germany),DSF(tracks),(ART-9XA+KIV+SAEC-308+TT-81+K-10R) in service mpd Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::stop Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::play index undefined Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CoreStateMachine::startPlaybackTimer Apr 14 22:21:33 volumio-r2r volumio[1138]: info: CorePlayQueue::getTrack 0 Apr 14 22:21:33 volumio-r2r volumio[1138]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Erdal/DSDTest/01 - David Elias - The Window - Vision of Her (DSD64).dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 22:21:33 volumio-r2r volumio[1138]: info: Apr 14 22:21:33 volumio-r2r volumio[1138]: ---------------------------- MPD announces state update: player Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F01%20-%20Good%20Times%20Bad%20Times.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/01 - Good Times Bad Times.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F02%20-%20Babe%20I'm%20Gonna%20Leave%20You.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/02 - Babe I'm Gonna Leave You.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F03%20-%20You%20Shook%20Me.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/03 - You Shook Me.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F04%20-%20Dazed%20And%20Confused.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/04 - Dazed And Confused.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F05%20-%20Your%20Time%20Is%20Gonna%20Come%20-%20Black%20Mountain%20Side.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/05 - Your Time Is Gonna Come - Black Mountain Side.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F06%20-%20Communication%20Breakdown.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/06 - Communication Breakdown.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F07%20-%20I%20Can't%20Quit%20You%20Baby.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/07 - I Can't Quit You Baby.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Led%20Zeppelin/Led%20Zeppelin/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F(uaoa)%20Led%20Zeppelin%20-%20Led%20Zeppelin%20-%201969%20(1979)%2F08%20-%20How%20Many%20More%20Times.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/(uaoa) Led Zeppelin - Led Zeppelin - 1969 (1979)/08 - How Many More Times.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Les%20Chats%20Noirs/Les%20Chats%20Noirs/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F5%20Tracks%20in%20DSD512-st%2F1.%20Les%20Chats%20Noirs-La%20Chanson-DSD512.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/5 Tracks in DSD512-st/1. Les Chats Noirs-La Chanson-DSD512.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Yuko%20Mabuchi%20(piano)%2C%20JJ%20Kirkpatrick%20(trumpet)%2C%20Del%20Atkins%20(bass)%2C%20Bobby%20Breton%20(drums)/Yuko%20Mabuchi%20plays%20Miles%20Davis/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F5%20Tracks%20in%20DSD512-st%2F2.%20Miles%20Davis-Milestones%2C%20Yuko%20Mabuchi-DSD512.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/5 Tracks in DSD512-st/2. Miles Davis-Milestones, Yuko Mabuchi-DSD512.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Rachel%20Podger%2C%20Brecon%20Baroque/Le%20Quattro%20Stagioni/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F5%20Tracks%20in%20DSD512-st%2F3.%20Vivaldi-The%20Four%20Seasons-Winter%2C%20Rachel%20Podger%2C%20Brecon%20Baroque-1.Largo-DSD512.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/5 Tracks in DSD512-st/3. Vivaldi-The Four Seasons-Winter, Rachel Podger, Brecon Baroque-1.Largo-DSD512.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Ricardo%20Gall%C3%A9n/En%20Silencio/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F5%20Tracks%20in%20DSD512-st%2F4.%20Barrios-La%20Catedral%2C%20Ricardo%20Gall%C3%A9n-3.Allegro%20solemne-DSD512.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/5 Tracks in DSD512-st/4. Barrios-La Catedral, Ricardo Gallén-3.Allegro solemne-DSD512.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Feenbrothers/Play%20Dave%20Brubeck/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2F5%20Tracks%20in%20DSD512-st%2F5.%20Dave%20Brubeck-Take%20Five%20Reprise%20(Desmond)%2C%20Feenbrothers-DSD512.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/5 Tracks in DSD512-st/5. Dave Brubeck-Take Five Reprise (Desmond), Feenbrothers-DSD512.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDeep%20Purple%20-%20Machine%20Head%20(1972%20UK)%2F01%20-%20Highway%20Star.dff&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK)/01 - Highway Star.dff Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDeep%20Purple%20-%20Machine%20Head%20(1972%20UK)%2F02%20-%20Maybe%20I'm%20A%20Leo.dff&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK)/02 - Maybe I'm A Leo.dff Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDeep%20Purple%20-%20Machine%20Head%20(1972%20UK)%2F03%20-%20Pictures%20Of%20Home.dff&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK)/03 - Pictures Of Home.dff Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDeep%20Purple%20-%20Machine%20Head%20(1972%20UK)%2F04%20-%20Never%20Before.dff&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK)/04 - Never Before.dff Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDeep%20Purple%20-%20Machine%20Head%20(1972%20UK)%2F05%20-%20Smoke%20On%20The%20Water.dff&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK)/05 - Smoke On The Water.dff Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDeep%20Purple%20-%20Machine%20Head%20(1972%20UK)%2F06%20-%20Lazy.dff&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK)/06 - Lazy.dff Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=//medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDeep%20Purple%20-%20Machine%20Head%20(1972%20UK)%2F07%20-%20Space%20Truckin'.dff&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Deep Purple - Machine Head (1972 UK)/07 - Space Truckin'.dff Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F01%20-%20So%20Far%20Away.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/01 - So Far Away.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F02%20-%20Money%20For%20Nothing.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/02 - Money For Nothing.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F03%20-%20Walk%20Of%20Life.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/03 - Walk Of Life.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F04%20-%20Your%20Latest%20Trick.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/04 - Your Latest Trick.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F05%20-%20Why%20Worry.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/05 - Why Worry.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F06%20-%20Ride%20Across%20The%20River.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/06 - Ride Across The River.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F07%20-%20The%20Man's%20Too%20Strong.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/07 - The Man's Too Strong.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F08%20-%20One%20World.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/08 - One World.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Dire%20Straits/Brothers%20In%20Arms/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FDire%20Straits%20-%20Brothers%20In%20Arms%201985%20UK%2F09%20-%20Brothers%20In%20Arms.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Dire Straits - Brothers In Arms 1985 UK/09 - Brothers In Arms.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Lipps%2C%20Inc./Mouth%20To%20Mouth%2C(CA2ML%2BNG-6%2B308%2BTT-81)/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FLipps%2C%20Inc.%20-%20Mouth%20To%20Mouth%20-%201980%2C(Holland)%2CDSF(tracks)%2C(CA2ML%2BNG-6%2B308%2BTT-81)%2FA1%20Funkytown.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Lipps, Inc. - Mouth To Mouth - 1980,(Holland),DSF(tracks),(CA2ML+NG-6+308+TT-81)/A1 Funkytown.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Lipps%2C%20Inc./Mouth%20To%20Mouth%2C(CA2ML%2BNG-6%2B308%2BTT-81)/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FLipps%2C%20Inc.%20-%20Mouth%20To%20Mouth%20-%201980%2C(Holland)%2CDSF(tracks)%2C(CA2ML%2BNG-6%2B308%2BTT-81)%2FA2%20All%20Night%20Dancing.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Lipps, Inc. - Mouth To Mouth - 1980,(Holland),DSF(tracks),(CA2ML+NG-6+308+TT-81)/A2 All Night Dancing.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Lipps%2C%20Inc./Mouth%20To%20Mouth%2C(CA2ML%2BNG-6%2B308%2BTT-81)/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FLipps%2C%20Inc.%20-%20Mouth%20To%20Mouth%20-%201980%2C(Holland)%2CDSF(tracks)%2C(CA2ML%2BNG-6%2B308%2BTT-81)%2FB1%20Rock%20It.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Lipps, Inc. - Mouth To Mouth - 1980,(Holland),DSF(tracks),(CA2ML+NG-6+308+TT-81)/B1 Rock It.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=Lipps%2C%20Inc./Mouth%20To%20Mouth%2C(CA2ML%2BNG-6%2B308%2BTT-81)/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FLipps%2C%20Inc.%20-%20Mouth%20To%20Mouth%20-%201980%2C(Holland)%2CDSF(tracks)%2C(CA2ML%2BNG-6%2B308%2BTT-81)%2FB2%20Power.dsf&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Lipps, Inc. - Mouth To Mouth - 1980,(Holland),DSF(tracks),(CA2ML+NG-6+308+TT-81)/B2 Power.dsf Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=/The%20Dark%20Side%20Of%20The%20Moon/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FPink%20Floyd%20-%20The%20Dark%20Side%20of%20the%20Moon%20(2016)%2FPink%20Floyd%20-%20The%20Dark%20Side%20of%20The%20Moon.cue&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Pink Floyd - The Dark Side of the Moon (2016)/Pink Floyd - The Dark Side of The Moon.cue Apr 14 22:21:33 volumio-r2r volumio[1138]: info: ALBUMART /albumart?cacheid=671&web=/The%20Dark%20Side%20Of%20The%20Moon/medium&path=%2Fmnt%2FINTERNAL%2FErdal%2FDSDTest%2FPink%20Floyd%20-%20The%20Dark%20Side%20of%20the%20Moon%20(2016)%2FPink%20Floyd%20-%20The%20Dark%20Side%20of%20The%20Moon.cue&metadata=false Apr 14 22:21:33 volumio-r2r volumio[1138]: info: URI /mnt/INTERNAL/Erdal/DSDTest/Pink Floyd - The Dark Side of the Moon (2016)/Pink Floyd - The Dark Side of The Moon.cue Apr 14 22:21:33 volumio-r2r volumio[1138]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 22:21:33 volumio-r2r volumio[1138]: Error: Unable to resolve or reject the same promise twice Apr 14 22:21:33 volumio-r2r volumio[1138]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 14 22:21:33 volumio-r2r volumio[1138]: at /volumio/app/plugins/music_service/mpd/index.js:2569:21 Apr 14 22:21:33 volumio-r2r volumio[1138]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Apr 14 22:21:33 volumio-r2r volumio[1138]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Apr 14 22:21:33 volumio-r2r volumio[1138]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Apr 14 22:21:33 volumio-r2r volumio[1138]: at Socket.emit (node:events:514:28) Apr 14 22:21:33 volumio-r2r volumio[1138]: at addChunk (node:internal/streams/readable:343:12) Apr 14 22:21:33 volumio-r2r volumio[1138]: at readableAddChunk (node:internal/streams/readable:312:11) Apr 14 22:21:33 volumio-r2r volumio[1138]: at Readable.push (node:internal/streams/readable:253:10) Apr 14 22:21:33 volumio-r2r volumio[1138]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Apr 14 22:21:33 volumio-r2r volumio[1138]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 22:21:34 volumio-r2r sudo[3548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 22:20' Apr 14 22:21:34 volumio-r2r sudo[3548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"