Feb 25 17:18:00 radio volumio[1778]: info: Loading plugin "outputs"... Feb 25 17:18:00 radio volumio[1778]: info: Loading plugin "albumart"... Feb 25 17:18:00 radio volumio[1778]: info: Plugin example_plugin is not enabled Feb 25 17:18:00 radio volumio[1778]: info: Loading plugin "inputs"... Feb 25 17:18:00 radio volumio[1778]: info: Loading plugin "updater_comm"... Feb 25 17:18:00 radio volumio[1778]: info: Plugin mpdemulation is not enabled Feb 25 17:18:00 radio volumio[1778]: info: Loading plugin "rest_api"... Feb 25 17:18:00 radio volumio[1778]: info: Loading plugin "websocket"... Feb 25 17:18:00 radio volumio[1778]: info: Starting Socket.io Server version 1.7.4 Feb 25 17:18:00 radio volumio[1778]: info: Loading plugin "scheduledrestart"... Feb 25 17:18:01 radio volumio[1778]: info: Applying required configuration parameters for plugin scheduledrestart Feb 25 17:18:01 radio CRON[1889]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0) Feb 25 17:18:01 radio CRON[1890]: (root) CMD (/home/volumio/network-monitor.sh) Feb 25 17:18:01 radio CRON[1889]: pam_unix(cron:session): session closed for user root Feb 25 17:18:01 radio volumio[1778]: info: Loading i18n strings for locale de Feb 25 17:18:01 radio volumio[1879]: Forking 3 albumart workers Feb 25 17:18:01 radio volumio[1778]: Updating browse sources language Feb 25 17:18:01 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::initPlayerControls Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 17:18:02 radio volumio[1778]: Express server listening on port 3000 Feb 25 17:18:02 radio volumio[1778]: [Metrics] WebUI: 13s 617.44ms Feb 25 17:18:02 radio volumio[1778]: info: CoreStateMachine::resetVolumioState Feb 25 17:18:02 radio volumio[1778]: info: CoreStateMachine::getcurrentVolume Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 17:18:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:03 radio volumio[1778]: info: Volumio Network Manager: Network status updated: 0 Feb 25 17:18:03 radio volumio[1778]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 25 17:18:03 radio volumio[1778]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Feb 25 17:18:03 radio volumio[1778]: info: Cannot use regular scanning, forcing with ap-force Feb 25 17:18:03 radio sudo[1939]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 25 17:18:03 radio sudo[1939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:05 radio volumio[1894]: Starting albumart workers Feb 25 17:18:06 radio sudo[1939]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:06 radio volumio[1893]: Starting albumart workers Feb 25 17:18:06 radio sudo[1945]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 17:18:06 radio sudo[1945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:06 radio sudo[1945]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:06 radio sudo[1947]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 17:18:06 radio sudo[1947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:06 radio sudo[1947]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:06 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="LuiseUndBoerniHaus" Feb 25 17:18:06 radio wpa_supplicant[983]: wlan0: Trying to associate with dc:39:6f:2a:6c:39 (SSID='LuiseUndBoerniHaus' freq=2452 MHz) Feb 25 17:18:07 radio volumio[1778]: info: Reloading queue from file Feb 25 17:18:07 radio volumio[1892]: Starting albumart workers Feb 25 17:18:07 radio volumio[1778]: info: VolumeController:: Volume=42 Mute =false Feb 25 17:18:07 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:18:07 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:18:07 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 17:18:07 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:18:07 radio volumio[1778]: info: CoreStateMachine::updateTrackBlock Feb 25 17:18:07 radio volumio[1778]: info: CorePlayQueue::getTrackBlock Feb 25 17:18:07 radio volumio[1778]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 17:18:07 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Feb 25 17:18:07 radio wpa_supplicant[983]: BSSID dc:39:6f:2a:6c:39 ignore list count incremented to 3, ignoring for 60 seconds Feb 25 17:18:07 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="LuiseUndBoerniHaus" auth_failures=2 duration=32 reason=CONN_FAILED Feb 25 17:18:07 radio volumio[1778]: info: CoreStateMachine::setRepeat null single undefined Feb 25 17:18:07 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:18:07 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:18:07 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:18:07 radio volumio[1778]: info: CoreStateMachine::setRandom null Feb 25 17:18:07 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:18:07 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:18:07 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:18:07 radio volumio[1778]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 25 17:18:07 radio volumio[1778]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03115 Feb 25 17:18:07 radio volumio[1778]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 25 17:18:07 radio volumio[1778]: info: Setting Device type: Raspberry PI Feb 25 17:18:07 radio volumio[1778]: info: VolumeController:: Volume=42 Mute =false Feb 25 17:18:07 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:18:07 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:18:07 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:18:07 radio volumio[1778]: info: Discovery: adding 2a3d411d-6446-46c7-b0d9-785cf44b3a69 Feb 25 17:18:07 radio volumio[1778]: info: Discovery: Found device Radio Feb 25 17:18:07 radio volumio[1778]: info: CoreCommandRouter::volumioGetState Feb 25 17:18:07 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:18:07 radio sudo[1962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 17:18:07 radio sudo[1962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:07 radio volumio[1778]: info: Completed loading Core Plugins Feb 25 17:18:07 radio volumio[1778]: info: Preparing to generate the ALSA configuration file Feb 25 17:18:08 radio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 17:18:08 radio sudo[1962]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:08 radio volumio[1778]: info: Asound.conf file unchanged, so no further update is needed Feb 25 17:18:08 radio volumio[1778]: info: Output device has changed, restarting MPD Feb 25 17:18:08 radio volumio[1778]: info: Output device has changed, restarting Shairport Sync Feb 25 17:18:08 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:08 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:08 radio sudo[1973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 17:18:08 radio sudo[1973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:08 radio sudo[1973]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:08 radio sudo[1977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 17:18:08 radio sudo[1977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:08 radio volumio[1778]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 17:18:08 radio volumio[1778]: info: ___________ START PLUGINS ___________ Feb 25 17:18:08 radio volumio[1778]: info: ControllerMpd::onStart: Initializing MPD Feb 25 17:18:08 radio volumio[1778]: info: Creating MPD Configuration file Feb 25 17:18:08 radio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 17:18:08 radio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 17:18:08 radio sudo[1984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 17:18:08 radio sudo[1984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:08 radio sudo[1984]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:08 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 17:18:08 radio volumio[1778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 17:18:08 radio volumio[1778]: info: [1772036288698] CoreMusicLibrary::Adding element Medienserver Feb 25 17:18:08 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 17:18:08 radio sudo[1988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 17:18:08 radio sudo[1986]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 17:18:08 radio sudo[1986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 17:18:08 radio sudo[1989]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 25 17:18:08 radio sudo[1986]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:08 radio sudo[1988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:08 radio systemd[1]: mpd.service: Deactivated successfully. Feb 25 17:18:08 radio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 17:18:08 radio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 17:18:08 radio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 17:18:08 radio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 17:18:08 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:08 radio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 17:18:08 radio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 17:18:08 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:09 radio sudo[1993]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 17:18:09 radio sudo[1999]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 25 17:18:09 radio sudo[1993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 17:18:09 radio sudo[1993]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:09 radio volumio[1778]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 17:18:09 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:09 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:09 radio volumio[1778]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 17:18:09 radio volumio[1778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 17:18:09 radio volumio[1778]: info: [1772036289599] CoreMusicLibrary::Adding element Last_100 Feb 25 17:18:09 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 17:18:09 radio volumio[1778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 17:18:09 radio volumio[1778]: info: [1772036289601] CoreMusicLibrary::Adding element Webradio Feb 25 17:18:09 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 17:18:09 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 17:18:09 radio volumio[1778]: info: Initializing BBC Radios Feb 25 17:18:10 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 17:18:10 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:10 radio volumio[1778]: info: Creating Spotify config file Feb 25 17:18:10 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:11 radio volumio[1778]: info: AutoStart - onStart Feb 25 17:18:12 radio volumio[1778]: info: [now-playing] ConfigUpdater: config is up to date. Feb 25 17:18:12 radio volumio[1778]: info: Scheduling reboots with hours: 1, minutes: 0 in timezone: Europe/Berlin Feb 25 17:18:12 radio volumio[1778]: info: Scheduling job with cron expression: 0 0 1 * * 0 Feb 25 17:18:12 radio volumio[1778]: info: Scheduling job with cron expression: 0 0 1 * * 1 Feb 25 17:18:12 radio volumio[1778]: info: Scheduling job with cron expression: 0 0 1 * * 2 Feb 25 17:18:12 radio volumio[1778]: info: Scheduling job with cron expression: 0 0 1 * * 3 Feb 25 17:18:12 radio volumio[1778]: info: Scheduling job with cron expression: 0 0 1 * * 4 Feb 25 17:18:12 radio volumio[1778]: info: Scheduling job with cron expression: 0 0 1 * * 5 Feb 25 17:18:12 radio volumio[1778]: info: Scheduling job with cron expression: 0 0 1 * * 6 Feb 25 17:18:12 radio volumio[1778]: info: Volumio Calling Home Feb 25 17:18:12 radio volumio-remote-updater[783]: [2026-02-25 17:18:12] [connect] Successful connection Feb 25 17:18:13 radio mpd[2000]: 2026-02-25T17:18:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 17:18:13 radio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 17:18:13 radio sudo[1988]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:13 radio sudo[1977]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:13 radio volumio[1778]: info: [now-playing] App is listening on port 4004. Feb 25 17:18:13 radio volumio[1778]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 25 17:18:13 radio volumio[1778]: Unhandled rejection Error: No sockets available, cannot start. Feb 25 17:18:13 radio volumio[1778]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Feb 25 17:18:13 radio volumio[1778]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Feb 25 17:18:13 radio volumio[1778]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Feb 25 17:18:13 radio volumio[1778]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Feb 25 17:18:13 radio volumio[1778]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Feb 25 17:18:13 radio volumio[1778]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Feb 25 17:18:13 radio volumio[1778]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Feb 25 17:18:13 radio volumio[1778]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Feb 25 17:18:13 radio volumio[1778]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Feb 25 17:18:13 radio volumio[1778]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Feb 25 17:18:13 radio volumio[1778]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Feb 25 17:18:13 radio volumio[1778]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Feb 25 17:18:13 radio volumio[1778]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Feb 25 17:18:13 radio volumio[1778]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Feb 25 17:18:13 radio volumio[1778]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Feb 25 17:18:13 radio volumio[1778]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 25 17:18:13 radio volumio[1778]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Feb 25 17:18:13 radio volumio[1778]: info: Upmpdcli Daemon Started Feb 25 17:18:13 radio volumio[1778]: info: Completed starting Core Plugins Feb 25 17:18:13 radio volumio[1778]: info: ------------------------------------------- Feb 25 17:18:13 radio volumio[1778]: info: ----- MyVolumio plugins startup ---- Feb 25 17:18:13 radio volumio[1778]: info: ------------------------------------------- Feb 25 17:18:13 radio volumio[1778]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 17:18:13 radio volumio[1778]: info: MPD Permissions set Feb 25 17:18:13 radio volumio[1778]: info: MPD Permissions set Feb 25 17:18:14 radio volumio-remote-updater[783]: [2026-02-25 17:18:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772036292 101 Feb 25 17:18:14 radio volumio[1778]: 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: 1 Feb 25 17:18:14 radio volumio[1778]: info: MPD running with PID2000 Feb 25 17:18:14 radio volumio[1778]: ,establishing connection Feb 25 17:18:14 radio volumio[1778]: info: Spotify config file written Feb 25 17:18:14 radio sudo[2062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 17:18:14 radio sudo[2062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:14 radio volumio[1778]: error: MPD error: The expression evaluated to a falsy value: Feb 25 17:18:14 radio volumio[1778]: assert.ok(self.idling) Feb 25 17:18:14 radio 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. Feb 25 17:18:14 radio 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. Feb 25 17:18:14 radio volumio[1778]: error: The expression evaluated to a falsy value: Feb 25 17:18:14 radio volumio[1778]: assert.ok(self.idling) Feb 25 17:18:14 radio volumio[1778]: error: MPD error: The expression evaluated to a falsy value: Feb 25 17:18:14 radio volumio[1778]: assert.ok(self.idling) Feb 25 17:18:14 radio volumio[1778]: error: The expression evaluated to a falsy value: Feb 25 17:18:14 radio volumio[1778]: assert.ok(self.idling) Feb 25 17:18:14 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:14 radio sudo[2062]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:14 radio go-librespot[2064]: go-librespot daemon starting... Feb 25 17:18:14 radio volumio[1778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:14 radio volumio[1778]: info: No need to fix Spotify hosts Feb 25 17:18:14 radio go-librespot[2065]: time="2026-02-25T17:18:14+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:14 radio go-librespot[2065]: time="2026-02-25T17:18:14+01:00" level=debug msg="app state loaded" Feb 25 17:18:14 radio go-librespot[2065]: time="2026-02-25T17:18:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:14 radio go-librespot[2065]: time="2026-02-25T17:18:14+01: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" Feb 25 17:18:14 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:14 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:15 radio volumio[1778]: error: updateQueue error: null Feb 25 17:18:15 radio volumio[1778]: info: Starting Shairport Sync Feb 25 17:18:15 radio volumio[1778]: info: Starting Shairport Sync Feb 25 17:18:15 radio volumio[1778]: info: Starting Shairport Sync Feb 25 17:18:15 radio sudo[2082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 17:18:15 radio sudo[2082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:15 radio sudo[2084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 17:18:15 radio sudo[2084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:15 radio sudo[2086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 17:18:15 radio sudo[2086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:15 radio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 17:18:15 radio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 17:18:15 radio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 17:18:15 radio systemd[1]: shairport-sync.service: Consumed 1.513s CPU time. Feb 25 17:18:15 radio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 17:18:15 radio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 17:18:15 radio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 17:18:15 radio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 17:18:15 radio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 17:18:15 radio sudo[2082]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:15 radio volumio[1778]: info: CoreCommandRouter::volumioGetState Feb 25 17:18:15 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:18:15 radio sudo[2086]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:15 radio sudo[2084]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:15 radio volumio[1778]: info: Shairport-Sync Started Feb 25 17:18:15 radio volumio[1778]: Error adding Membership: Error: addMembership EINVAL Feb 25 17:18:15 radio volumio[1778]: info: Shairport-Sync Started Feb 25 17:18:15 radio volumio[1778]: info: Shairport-Sync Started Feb 25 17:18:17 radio sudo[2116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 25 17:18:17 radio sudo[2116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:17 radio sudo[2118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 25 17:18:17 radio sudo[2118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 17:18:17 radio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 25 17:18:17 radio mpd_monitor.sh[2120]: MPD Monitor Service: Starting MPD Monitor Service Feb 25 17:18:17 radio sudo[2116]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:17 radio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 25 17:18:17 radio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 25 17:18:17 radio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 25 17:18:17 radio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 25 17:18:17 radio volumio[1778]: info: Successfully started MPD Monitor Feb 25 17:18:17 radio mpd_monitor.sh[2124]: MPD Monitor Service: Starting MPD Monitor Service Feb 25 17:18:17 radio sudo[2118]: pam_unix(sudo:session): session closed for user root Feb 25 17:18:17 radio volumio[1778]: info: Successfully started MPD Monitor Feb 25 17:18:17 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 17:18:17 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:18 radio volumio[1778]: info: go-librespot daemon successfully initialized Feb 25 17:18:18 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:18 radio go-librespot[2128]: go-librespot daemon starting... Feb 25 17:18:18 radio go-librespot[2129]: time="2026-02-25T17:18:18+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:18 radio go-librespot[2129]: time="2026-02-25T17:18:18+01:00" level=debug msg="app state loaded" Feb 25 17:18:18 radio go-librespot[2129]: time="2026-02-25T17:18:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:18 radio go-librespot[2129]: time="2026-02-25T17:18:18+01: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" Feb 25 17:18:18 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:18 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:19 radio volumio[1778]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 17:18:21 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:21 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:21 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 17:18:21 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:21 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:21 radio go-librespot[2135]: go-librespot daemon starting... Feb 25 17:18:21 radio go-librespot[2136]: time="2026-02-25T17:18:21+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:21 radio go-librespot[2136]: time="2026-02-25T17:18:21+01:00" level=debug msg="app state loaded" Feb 25 17:18:21 radio go-librespot[2136]: time="2026-02-25T17:18:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:21 radio go-librespot[2136]: time="2026-02-25T17:18:21+01: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" Feb 25 17:18:21 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:21 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:24 radio volumio[1778]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.072&uuid=1638db5b4bc48e70fa67aacf9ebe3829" http://updates.volumio.org/downloader-v1/track-device Feb 25 17:18:24 radio volumio[1778]: % Total % Received % Xferd Average Speed Time Time Time Current Feb 25 17:18:24 radio volumio[1778]: Dload Upload Total Spent Left Speed Feb 25 17:18:24 radio volumio[1778]: [132B blob data] Feb 25 17:18:24 radio volumio[1778]: retrying in 5 seconds, trial 0 Feb 25 17:18:24 radio volumio[1778]: info: Volumio Calling Home Feb 25 17:18:24 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:24 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:24 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 17:18:24 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:24 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:24 radio go-librespot[2159]: go-librespot daemon starting... Feb 25 17:18:24 radio go-librespot[2160]: time="2026-02-25T17:18:24+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:24 radio go-librespot[2160]: time="2026-02-25T17:18:24+01:00" level=debug msg="app state loaded" Feb 25 17:18:24 radio go-librespot[2160]: time="2026-02-25T17:18:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:24 radio go-librespot[2160]: time="2026-02-25T17:18:24+01: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" Feb 25 17:18:24 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:24 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:27 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:27 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:27 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 25 17:18:27 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:27 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:27 radio go-librespot[2166]: go-librespot daemon starting... Feb 25 17:18:27 radio go-librespot[2167]: time="2026-02-25T17:18:27+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:27 radio go-librespot[2167]: time="2026-02-25T17:18:27+01:00" level=debug msg="app state loaded" Feb 25 17:18:27 radio go-librespot[2167]: time="2026-02-25T17:18:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:27 radio go-librespot[2167]: time="2026-02-25T17:18:27+01: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" Feb 25 17:18:27 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:27 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:30 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:30 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:30 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 25 17:18:30 radio systemd[1]: dev-dri-card0.device: Job dev-dri-card0.device/start timed out. Feb 25 17:18:30 radio systemd[1]: Timed out waiting for device dev-dri-card0.device - /dev/dri/card0. Feb 25 17:18:30 radio systemd[1]: dev-dri-card0.device: Job dev-dri-card0.device/start failed with result 'timeout'. Feb 25 17:18:30 radio systemd[1]: dev-dri-renderD128.device: Job dev-dri-renderD128.device/start timed out. Feb 25 17:18:30 radio systemd[1]: Timed out waiting for device dev-dri-renderD128.device - /dev/dri/renderD128. Feb 25 17:18:30 radio systemd[1]: dev-dri-renderD128.device: Job dev-dri-renderD128.device/start failed with result 'timeout'. Feb 25 17:18:30 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:31 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:31 radio systemd[1]: Starting lightdm.service - Light Display Manager... Feb 25 17:18:31 radio go-librespot[2173]: go-librespot daemon starting... Feb 25 17:18:31 radio go-librespot[2175]: time="2026-02-25T17:18:31+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:31 radio go-librespot[2175]: time="2026-02-25T17:18:31+01:00" level=debug msg="app state loaded" Feb 25 17:18:31 radio go-librespot[2175]: time="2026-02-25T17:18:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:31 radio go-librespot[2175]: time="2026-02-25T17:18:31+01: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" Feb 25 17:18:31 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:31 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:31 radio systemd[1]: Received SIGRTMIN+21 from PID 305 (plymouthd). Feb 25 17:18:31 radio systemd[1]: Received SIGRTMIN+21 from PID 305 (plymouthd). Feb 25 17:18:31 radio systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Feb 25 17:18:31 radio systemd[1]: Started getty@tty1.service - Getty on tty1. Feb 25 17:18:31 radio systemd[1]: Reached target getty.target - Login Prompts. Feb 25 17:18:31 radio systemd[1]: Started lightdm.service - Light Display Manager. Feb 25 17:18:32 radio lightdm[2198]: pam_unix(lightdm-autologin:session): session opened for user volumio(uid=1000) by (uid=0) Feb 25 17:18:32 radio systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Feb 25 17:18:32 radio systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Feb 25 17:18:32 radio systemd-logind[773]: New session 2 of user volumio. Feb 25 17:18:32 radio systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Feb 25 17:18:32 radio systemd[1]: Starting user@1000.service - User Manager for UID 1000... Feb 25 17:18:32 radio (systemd)[2203]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Feb 25 17:18:32 radio systemd-xdg-autostart-generator[2217]: Configuration file /home/volumio/.config/autostart/chromium.desktop is marked executable. Please remove executable permission bits. Proceeding anyway. Feb 25 17:18:32 radio systemd-xdg-autostart-generator[2217]: /home/volumio/.config/autostart/chromium.desktop:12: Key Name was defined multiple times, ignoring. Feb 25 17:18:33 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:33 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:33 radio systemd[2203]: Queued start job for default target default.target. Feb 25 17:18:33 radio systemd[2203]: Created slice app.slice - User Application Slice. Feb 25 17:18:33 radio systemd[2203]: Created slice session.slice - User Core Session Slice. Feb 25 17:18:33 radio systemd[2203]: drkonqi-coredump-cleanup.timer - Cleanup lingering KCrash metadata was skipped because of an unmet condition check (ConditionPathExistsGlob=/home/volumio/.cache/kcrash-metadata/*.ini). Feb 25 17:18:33 radio systemd[2203]: Reached target paths.target - Paths. Feb 25 17:18:33 radio systemd[2203]: Reached target timers.target - Timers. Feb 25 17:18:33 radio systemd[2203]: Starting dbus.socket - D-Bus User Message Bus Socket... Feb 25 17:18:33 radio systemd[2203]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Feb 25 17:18:33 radio systemd[2203]: Listening on drkonqi-coredump-launcher.socket - Socket to launch DrKonqi for a systemd-coredump crash. Feb 25 17:18:33 radio systemd[2203]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Feb 25 17:18:33 radio systemd[2203]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Feb 25 17:18:33 radio systemd[2203]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Feb 25 17:18:33 radio systemd[2203]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Feb 25 17:18:33 radio systemd[2203]: Listening on pk-debconf-helper.socket - debconf communication socket. Feb 25 17:18:33 radio systemd[2203]: Listening on pulseaudio.socket - Sound System. Feb 25 17:18:33 radio systemd[2203]: Listening on snapd.session-agent.socket - REST API socket for snapd user session agent. Feb 25 17:18:33 radio systemd[2203]: Listening on dbus.socket - D-Bus User Message Bus Socket. Feb 25 17:18:33 radio systemd[2203]: Reached target sockets.target - Sockets. Feb 25 17:18:33 radio systemd[2203]: Reached target basic.target - Basic System. Feb 25 17:18:33 radio systemd[1]: Started user@1000.service - User Manager for UID 1000. Feb 25 17:18:33 radio systemd[2203]: drkonqi-coredump-cleanup.service - Cleanup lingering KCrash metadata was skipped because of an unmet condition check (ConditionPathExistsGlob=/home/volumio/.cache/kcrash-metadata/*.ini). Feb 25 17:18:33 radio systemd[1]: Started session-2.scope - Session 2 of User volumio. Feb 25 17:18:33 radio systemd[2203]: Started mpris-proxy.service - Bluetooth mpris proxy. Feb 25 17:18:33 radio systemd[2203]: Starting pulseaudio.service - Sound Service... Feb 25 17:18:33 radio systemd[2203]: Starting dbus.service - D-Bus User Message Bus... Feb 25 17:18:33 radio dbus-daemon[750]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.28' (uid=1000 pid=2220 comm="/usr/bin/pulseaudio --daemonize=no --log-target=jo") Feb 25 17:18:33 radio systemd[1]: Starting rtkit-daemon.service - RealtimeKit Scheduling Policy Service... Feb 25 17:18:33 radio systemd[2203]: Started dbus.service - D-Bus User Message Bus. Feb 25 17:18:33 radio dbus-daemon[750]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Feb 25 17:18:33 radio systemd[1]: Started rtkit-daemon.service - RealtimeKit Scheduling Policy Service. Feb 25 17:18:33 radio rtkit-daemon[2222]: Successfully called chroot. Feb 25 17:18:33 radio rtkit-daemon[2222]: Successfully dropped privileges. Feb 25 17:18:33 radio rtkit-daemon[2222]: Successfully limited resources. Feb 25 17:18:33 radio rtkit-daemon[2222]: Canary thread running. Feb 25 17:18:33 radio rtkit-daemon[2222]: Watchdog thread running. Feb 25 17:18:33 radio rtkit-daemon[2222]: Running. Feb 25 17:18:33 radio rtkit-daemon[2222]: Successfully made thread 2220 of process 2220 owned by '1000' high priority at nice level -11. Feb 25 17:18:33 radio rtkit-daemon[2222]: Supervising 1 threads of 1 processes of 1 users. Feb 25 17:18:33 radio volumio[1778]: error: MyVolumio Plugin failed to start in a timely fashion Feb 25 17:18:33 radio volumio[1778]: [Metrics] CommandRouter: 44s 88.07ms Feb 25 17:18:33 radio volumio[1778]: info: CoreCommandRouter::volumiosetStartupVolume Feb 25 17:18:33 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 17:18:33 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:33 radio volumio[1778]: info: CoreCommandRouter::Close All Modals sent Feb 25 17:18:33 radio volumio[1778]: info: CoreCommandRouter::Close All Modals sent Feb 25 17:18:34 radio volumio[1778]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.072&uuid=1638db5b4bc48e70fa67aacf9ebe3829" http://updates.volumio.org/downloader-v1/track-device Feb 25 17:18:34 radio volumio[1778]: % Total % Received % Xferd Average Speed Time Time Time Current Feb 25 17:18:34 radio volumio[1778]: Dload Upload Total Spent Left Speed Feb 25 17:18:34 radio volumio[1778]: [132B blob data] Feb 25 17:18:34 radio volumio[1778]: retrying in 5 seconds, trial 1 Feb 25 17:18:34 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 25 17:18:34 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:34 radio volumio[1778]: info: Volumio Calling Home Feb 25 17:18:34 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:34 radio go-librespot[2259]: go-librespot daemon starting... Feb 25 17:18:34 radio go-librespot[2262]: time="2026-02-25T17:18:34+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:34 radio go-librespot[2262]: time="2026-02-25T17:18:34+01:00" level=debug msg="app state loaded" Feb 25 17:18:34 radio go-librespot[2262]: time="2026-02-25T17:18:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:34 radio go-librespot[2262]: time="2026-02-25T17:18:34+01: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" Feb 25 17:18:34 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:34 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:34 radio dbus-daemon[750]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.30' (uid=1000 pid=2220 comm="/usr/bin/pulseaudio --daemonize=no --log-target=jo") Feb 25 17:18:34 radio dbus-daemon[750]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service not found. Feb 25 17:18:34 radio systemd[2203]: Started pulseaudio.service - Sound Service. Feb 25 17:18:34 radio systemd[2203]: Reached target default.target - Main User Target. Feb 25 17:18:34 radio systemd[2203]: Startup finished in 2.279s. Feb 25 17:18:34 radio pulseaudio[2220]: GetManagedObjects() failed: org.freedesktop.systemd1.NoSuchUnit: Unit dbus-org.bluez.service not found. Feb 25 17:18:34 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 25 17:18:34 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 25 17:18:35 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 25 17:18:36 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:36 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:37 radio login[2190]: pam_unix(login:session): session opened for user volumio(uid=1000) by LOGIN(uid=0) Feb 25 17:18:37 radio systemd-logind[773]: New session 4 of user volumio. Feb 25 17:18:37 radio systemd[1]: Started session-4.scope - Session 4 of User volumio. Feb 25 17:18:37 radio systemd[2203]: Reloading. Feb 25 17:18:37 radio systemd-xdg-autostart-generator[2335]: Configuration file /home/volumio/.config/autostart/chromium.desktop is marked executable. Please remove executable permission bits. Proceeding anyway. Feb 25 17:18:37 radio systemd-xdg-autostart-generator[2335]: /home/volumio/.config/autostart/chromium.desktop:12: Key Name was defined multiple times, ignoring. Feb 25 17:18:37 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 25 17:18:37 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:37 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:37 radio go-librespot[2339]: go-librespot daemon starting... Feb 25 17:18:37 radio go-librespot[2340]: time="2026-02-25T17:18:37+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:37 radio go-librespot[2340]: time="2026-02-25T17:18:37+01:00" level=debug msg="app state loaded" Feb 25 17:18:37 radio go-librespot[2340]: time="2026-02-25T17:18:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:37 radio go-librespot[2340]: time="2026-02-25T17:18:37+01: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" Feb 25 17:18:37 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:37 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:37 radio systemd[2203]: /run/user/1000/systemd/generator.late/app-chromium@autostart.service:18: WorkingDirectory= path is not absolute, ignoring: Feb 25 17:18:38 radio systemd[2203]: Created slice background.slice - User Background Tasks Slice. Feb 25 17:18:38 radio systemd[2203]: Starting kde-baloo.service - Baloo File Indexer Daemon... Feb 25 17:18:38 radio systemd[2203]: Starting plasma-kcminit.service - KDE Config Module Initialization... Feb 25 17:18:38 radio systemd[2203]: Started ssh-agent.service - OpenSSH Agent. Feb 25 17:18:38 radio systemd[2203]: Starting xdg-desktop-portal-rewrite-launchers.service - Rewrite dynamic launcher portal entries... Feb 25 17:18:38 radio systemd[2203]: Finished xdg-desktop-portal-rewrite-launchers.service - Rewrite dynamic launcher portal entries. Feb 25 17:18:38 radio systemd[2203]: Reached target graphical-session-pre.target - Session services which should run early before the graphical session is brought up. Feb 25 17:18:38 radio baloo_file[2353]: Baloo File Indexing has been disabled Feb 25 17:18:38 radio systemd[1]: nmbd.service: start operation timed out. Terminating. Feb 25 17:18:38 radio systemd[2203]: Started kde-baloo.service - Baloo File Indexer Daemon. Feb 25 17:18:38 radio systemd[1]: nmbd.service: Failed with result 'timeout'. Feb 25 17:18:38 radio systemd[1]: Failed to start nmbd.service - Samba NMB Daemon. Feb 25 17:18:38 radio systemd[1]: Starting winbind.service - Samba Winbind Daemon... Feb 25 17:18:38 radio kcminit_startup[2352]: Initializing "/usr/lib/arm-linux-gnueabihf/qt5/plugins/plasma/kcms/systemsettings/kcm_fonts.so" Feb 25 17:18:38 radio kcminit_startup[2352]: Initializing "/usr/lib/arm-linux-gnueabihf/qt5/plugins/plasma/kcms/systemsettings/kcm_mouse.so" Feb 25 17:18:38 radio kcminit_startup[2352]: Initializing "/usr/lib/arm-linux-gnueabihf/qt5/plugins/plasma/kcms/systemsettings/kcm_style.so" Feb 25 17:18:38 radio systemd[2203]: Started plasma-kcminit.service - KDE Config Module Initialization. Feb 25 17:18:38 radio systemd[2203]: Starting plasma-ksmserver.service - KDE Session Management Server... Feb 25 17:18:38 radio systemd[2203]: Started plasma-kwallet-pam.service - Unlock kwallet from pam credentials. Feb 25 17:18:38 radio systemd[2203]: Starting plasma-kded.service - KDE Daemon... Feb 25 17:18:38 radio systemd[2203]: Starting plasma-kwin_x11.service - KDE Window Manager... Feb 25 17:18:39 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:39 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:39 radio kded5[2366]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:39 radio kded5[2366]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:39 radio kded5[2366]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:39 radio kded5[2366]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:39 radio kded5[2366]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:40 radio ksmserver[2364]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:40 radio ksmserver[2364]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:40 radio ksmserver[2364]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:40 radio ksmserver[2364]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:40 radio ksmserver[2364]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:40 radio systemd[2203]: Started plasma-kded.service - KDE Daemon. Feb 25 17:18:40 radio systemd[2203]: Starting plasma-kcminit-phase1.service - KDE Configuration Module Initialization (Phase 1)... Feb 25 17:18:40 radio kcminit_startup[2352]: Initializing "/usr/lib/arm-linux-gnueabihf/qt5/plugins/plasma/kcms/systemsettings/kcm_touchpad.so" Feb 25 17:18:40 radio kcminit_startup[2352]: kcm_touchpad: Using X11 backend Feb 25 17:18:40 radio kcminit_startup[2352]: Initializing "/usr/lib/arm-linux-gnueabihf/qt5/plugins/plasma/kcms/systemsettings/kcm_kgamma.so" Feb 25 17:18:40 radio winbindd[2369]: [2026/02/25 17:18:40.699300, 0] ../../source3/winbindd/winbindd.c:1440(main) Feb 25 17:18:40 radio systemd[2203]: Finished plasma-kcminit-phase1.service - KDE Configuration Module Initialization (Phase 1). Feb 25 17:18:40 radio winbindd[2369]: winbindd version 4.17.8-Raspbian started. Feb 25 17:18:40 radio winbindd[2369]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Feb 25 17:18:40 radio ksmserver[2364]: Qt: Session management error: networkIdsList argument is NULL Feb 25 17:18:40 radio kwin_x11[2367]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:40 radio winbindd[2369]: [2026/02/25 17:18:40.811046, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Feb 25 17:18:40 radio winbindd[2369]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 25 17:18:40 radio kwin_x11[2367]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:40 radio kwin_x11[2367]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:40 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 25 17:18:40 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:40 radio kwin_x11[2367]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:40 radio kwin_x11[2367]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:40 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:40 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.kde.kglobalaccel' unit='plasma-kglobalaccel.service' requested by ':1.11' (uid=1000 pid=2364 comm="/usr/bin/ksmserver") Feb 25 17:18:40 radio systemd[2203]: Starting plasma-kglobalaccel.service - KDE Global Shortcuts Server... Feb 25 17:18:40 radio systemd[1]: Started winbind.service - Samba Winbind Daemon. Feb 25 17:18:41 radio go-librespot[2410]: go-librespot daemon starting... Feb 25 17:18:41 radio volumio[1778]: info: BOOT COMPLETED Feb 25 17:18:41 radio systemd[1]: Starting smbd.service - Samba SMB Daemon... Feb 25 17:18:41 radio go-librespot[2414]: time="2026-02-25T17:18:41+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:41 radio go-librespot[2414]: time="2026-02-25T17:18:41+01:00" level=debug msg="app state loaded" Feb 25 17:18:41 radio go-librespot[2414]: time="2026-02-25T17:18:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:41 radio go-librespot[2414]: time="2026-02-25T17:18:41+01: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" Feb 25 17:18:41 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:41 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:41 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.kde.kglobalaccel' Feb 25 17:18:41 radio systemd[2203]: Started plasma-kglobalaccel.service - KDE Global Shortcuts Server. Feb 25 17:18:41 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="LuiseUndBoerniHaus" Feb 25 17:18:41 radio wpa_supplicant[983]: wlan0: Trying to associate with 10:3c:59:27:d5:57 (SSID='LuiseUndBoerniHaus' freq=2452 MHz) Feb 25 17:18:41 radio kded5[2366]: kcm_touchpad: Using X11 backend Feb 25 17:18:41 radio ksmserver[2364]: QDBusConnection: name 'org.kde.kglobalaccel' had owner '' but we thought it was ':1.12' Feb 25 17:18:41 radio ksmserver[2435]: /usr/bin/iceauth: creating new authority file /run/user/1000/ICEauthority Feb 25 17:18:41 radio systemd[2203]: Started plasma-ksmserver.service - KDE Session Management Server. Feb 25 17:18:41 radio systemd[2203]: Starting plasma-plasmashell.service - KDE Plasma Workspace... Feb 25 17:18:42 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 Feb 25 17:18:42 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="LuiseUndBoerniHaus" auth_failures=3 duration=42 reason=CONN_FAILED Feb 25 17:18:42 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 17:18:42 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 17:18:42 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 25 17:18:42 radio kded5[2366]: org.kde.libkbolt: Failed to connect to Bolt manager DBus interface: Feb 25 17:18:42 radio kded5[2366]: org.kde.bolt.kded: Couldn't connect to Bolt DBus daemon Feb 25 17:18:42 radio NetworkManager[959]: [1772036322.2339] agent-manager: agent[cdd55af77e28b955,:1.32/org.kde.plasma.networkmanagement/1000]: agent registered Feb 25 17:18:42 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.kde.ActivityManager' unit='plasma-kactivitymanagerd.service' requested by ':1.9' (uid=1000 pid=2366 comm="/usr/bin/kded5") Feb 25 17:18:42 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:42 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:42 radio systemd[2203]: Starting plasma-kactivitymanagerd.service - KActivityManager Activity manager Service... Feb 25 17:18:42 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='ca.desrt.dconf' unit='dconf.service' requested by ':1.14' (uid=1000 pid=2366 comm="/usr/bin/kded5") Feb 25 17:18:42 radio systemd[2203]: Starting dconf.service - User preferences database... Feb 25 17:18:42 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'ca.desrt.dconf' Feb 25 17:18:42 radio systemd[2203]: Started dconf.service - User preferences database. Feb 25 17:18:42 radio kwin_x11[2367]: kwin_platform_x11_standalone: Bogus refresh rate 0 Feb 25 17:18:42 radio kded5[2465]: xsettingsd: Loaded 13 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:42 radio kwin_x11[2367]: kwin_xkbcommon: XKB: inet:334:58: unrecognized keysym "XF86EmojiPicker" Feb 25 17:18:42 radio kded5[2465]: xsettingsd: Created window 0x1e00001 on screen 0 with timestamp 117033 Feb 25 17:18:42 radio kded5[2465]: xsettingsd: Selection _XSETTINGS_S0 is owned by 0x0 Feb 25 17:18:42 radio kded5[2465]: xsettingsd: Took ownership of selection _XSETTINGS_S0 Feb 25 17:18:42 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:42 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:43 radio systemd[2203]: Started plasma-kwin_x11.service - KDE Window Manager. Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:43 radio plasmashell[2436]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:43 radio plasmashell[2436]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:43 radio plasmashell[2436]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:43 radio plasmashell[2436]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:43 radio plasmashell[2436]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:43 radio smbd[2438]: [2026/02/25 17:18:43.632840, 0] ../../source3/smbd/server.c:1741(main) Feb 25 17:18:43 radio smbd[2438]: smbd version 4.17.8-Raspbian started. Feb 25 17:18:43 radio smbd[2438]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:43 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:44 radio plasmashell[2436]: Checking screens: available: (QScreen(0x1586380, name="default")) redundant: QHash() fake: QSet() all: (QScreen(0x1586380, name="default")) Feb 25 17:18:44 radio plasmashell[2436]: Checking screens: available: (QScreen(0x1586380, name="default")) redundant: QHash() fake: QSet() all: (QScreen(0x1586380, name="default")) Feb 25 17:18:44 radio systemd[2203]: Started plasma-plasmashell.service - KDE Plasma Workspace. Feb 25 17:18:44 radio systemd[2203]: Reached target plasma-core.target - KDE Plasma Workspace Core. Feb 25 17:18:44 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 25 17:18:44 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:44 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:44 radio systemd[2203]: Started plasma-gmenudbusmenuproxy.service - Proxies GTK DBus menus to a Plasma readable format. Feb 25 17:18:44 radio volumio[1778]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.072&uuid=1638db5b4bc48e70fa67aacf9ebe3829" http://updates.volumio.org/downloader-v1/track-device Feb 25 17:18:44 radio volumio[1778]: % Total % Received % Xferd Average Speed Time Time Time Current Feb 25 17:18:44 radio volumio[1778]: Dload Upload Total Spent Left Speed Feb 25 17:18:44 radio volumio[1778]: [132B blob data] Feb 25 17:18:44 radio volumio[1778]: retrying in 5 seconds, trial 2 Feb 25 17:18:44 radio volumio[1778]: info: Volumio Calling Home Feb 25 17:18:44 radio systemd[2203]: Starting plasma-polkit-agent.service - KDE PolicyKit Authentication Agent... Feb 25 17:18:44 radio systemd[2203]: Starting plasma-powerdevil.service - Powerdevil... Feb 25 17:18:44 radio systemd[2203]: Started plasma-xembedsniproxy.service - Handle legacy xembed system tray icons. Feb 25 17:18:44 radio go-librespot[2505]: go-librespot daemon starting... Feb 25 17:18:44 radio go-librespot[2511]: time="2026-02-25T17:18:44+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:44 radio go-librespot[2511]: time="2026-02-25T17:18:44+01:00" level=debug msg="app state loaded" Feb 25 17:18:44 radio go-librespot[2511]: time="2026-02-25T17:18:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:44 radio go-librespot[2511]: time="2026-02-25T17:18:44+01: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" Feb 25 17:18:44 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:44 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:44 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:44 radio kded5[2465]: xsettingsd: Loaded 13 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:44 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:44 radio kded5[2465]: xsettingsd: Loaded 13 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:45 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:45 radio kded5[2465]: xsettingsd: Loaded 13 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:45 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:45 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:45 radio kded5[2465]: xsettingsd: Reloading configuration Feb 25 17:18:45 radio kded5[2465]: xsettingsd: Loaded 0 settings from /home/volumio/.config/xsettingsd/xsettingsd.conf Feb 25 17:18:45 radio systemd[1]: Started smbd.service - Samba SMB Daemon. Feb 25 17:18:45 radio systemd[1]: Reached target multi-user.target - Multi-User System. Feb 25 17:18:45 radio systemd[1]: Reached target graphical.target - Graphical Interface. Feb 25 17:18:45 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:45 radio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Feb 25 17:18:45 radio kded5[2366]: Installing the delayed initialization callback. Feb 25 17:18:45 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:45 radio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Feb 25 17:18:45 radio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Feb 25 17:18:45 radio systemd[1]: Startup finished in 14.008s (kernel) + 1min 45.652s (userspace) = 1min 59.660s. Feb 25 17:18:45 radio kded5[2366]: org.kde.kscreen.dpms: DPMS extension not available Feb 25 17:18:45 radio plasmashell[2436]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running. Feb 25 17:18:45 radio plasmashell[2436]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable. Feb 25 17:18:46 radio dbus-daemon[750]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service' requested by ':1.35' (uid=1000 pid=2507 comm="/usr/lib/arm-linux-gnueabihf/libexec/org_kde_power") Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:46 radio systemd[1]: Starting upower.service - Daemon for power management... Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:46 radio systemd[2203]: Started plasma-polkit-agent.service - KDE PolicyKit Authentication Agent. Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: New PolkitAgentListener 0x1da4700 Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: Adding new listener PolkitQt1::Agent::Listener(0x1d83620) for 0x1da4700 Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: Listener online Feb 25 17:18:46 radio polkitd[755]: Registered Authentication Agent for unix-session:2 (system bus name :1.38 [/usr/lib/arm-linux-gnueabihf/libexec/polkit-kde-authentication-agent-1], object path /org/kde/PolicyKit1/AuthenticationAgent, locale C.UTF-8) Feb 25 17:18:46 radio polkit-kde-authentication-agent-1[2506]: Authentication agent result: true Feb 25 17:18:47 radio dbus-daemon[750]: [system] Successfully activated service 'org.freedesktop.UPower' Feb 25 17:18:47 radio systemd[1]: Started upower.service - Daemon for power management. Feb 25 17:18:47 radio dbus-daemon[750]: [system] Activating service name='org.kde.powerdevil.discretegpuhelper' requested by ':1.35' (uid=1000 pid=2507 comm="/usr/lib/arm-linux-gnueabihf/libexec/org_kde_power") (using servicehelper) Feb 25 17:18:47 radio dbus-daemon[750]: [system] Successfully activated service 'org.kde.powerdevil.discretegpuhelper' Feb 25 17:18:47 radio dbus-daemon[750]: [system] Activating service name='org.kde.powerdevil.chargethresholdhelper' requested by ':1.35' (uid=1000 pid=2507 comm="/usr/lib/arm-linux-gnueabihf/libexec/org_kde_power") (using servicehelper) Feb 25 17:18:47 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 25 17:18:47 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:47 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:47 radio go-librespot[2575]: go-librespot daemon starting... Feb 25 17:18:47 radio go-librespot[2576]: time="2026-02-25T17:18:47+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:47 radio go-librespot[2576]: time="2026-02-25T17:18:47+01:00" level=debug msg="app state loaded" Feb 25 17:18:47 radio go-librespot[2576]: time="2026-02-25T17:18:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:47 radio go-librespot[2576]: time="2026-02-25T17:18:47+01: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" Feb 25 17:18:47 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:47 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:48 radio dbus-daemon[750]: [system] Successfully activated service 'org.kde.powerdevil.chargethresholdhelper' Feb 25 17:18:48 radio dbus-daemon[750]: [system] Activating service name='org.kde.powerdevil.backlighthelper' requested by ':1.35' (uid=1000 pid=2507 comm="/usr/lib/arm-linux-gnueabihf/libexec/org_kde_power") (using servicehelper) Feb 25 17:18:48 radio org.kde.powerdevil.backlighthelper[2586]: org.kde.powerdevil: no kernel backlight interface found Feb 25 17:18:48 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:48 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:48 radio dbus-daemon[750]: [system] Successfully activated service 'org.kde.powerdevil.backlighthelper' Feb 25 17:18:48 radio kwin_x11[2367]: OpenGL vendor string: Mesa Feb 25 17:18:48 radio kwin_x11[2367]: OpenGL renderer string: llvmpipe (LLVM 15.0.6, 128 bits) Feb 25 17:18:48 radio kwin_x11[2367]: OpenGL version string: OpenGL ES 3.2 Mesa 24.2.8-1~bpo12+rpt4 Feb 25 17:18:48 radio kwin_x11[2367]: OpenGL shading language version string: OpenGL ES GLSL ES 3.20 Feb 25 17:18:48 radio kwin_x11[2367]: Driver: LLVMpipe Feb 25 17:18:48 radio kwin_x11[2367]: GPU class: Unknown Feb 25 17:18:48 radio kwin_x11[2367]: OpenGL version: 3.2 Feb 25 17:18:48 radio kwin_x11[2367]: GLSL version: 3.20 Feb 25 17:18:48 radio kwin_x11[2367]: Mesa version: 24.2.8 Feb 25 17:18:48 radio kwin_x11[2367]: X server version: 1.21.1 Feb 25 17:18:48 radio kwin_x11[2367]: Linux kernel version: 6.12.47 Feb 25 17:18:48 radio kwin_x11[2367]: Requires strict binding: no Feb 25 17:18:48 radio kwin_x11[2367]: GLSL shaders: yes Feb 25 17:18:48 radio kwin_x11[2367]: Texture NPOT support: yes Feb 25 17:18:48 radio kwin_x11[2367]: Virtual Machine: no Feb 25 17:18:48 radio kwin_x11[2367]: kwin_scene_opengl: Creating the OpenGL rendering failed: "Required support for binding pixmaps to EGLImages not found, disabling compositing" Feb 25 17:18:48 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.kde.ActivityManager' Feb 25 17:18:48 radio plasmashell[2436]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running. Feb 25 17:18:48 radio plasmashell[2436]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable. Feb 25 17:18:48 radio systemd[2203]: Started plasma-kactivitymanagerd.service - KActivityManager Activity manager Service. Feb 25 17:18:48 radio kwin_x11[2367]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 805, resource id: 63, major code: 3 (GetWindowAttributes), minor code: 0 Feb 25 17:18:48 radio kwin_x11[2367]: qt.qpa.xcb: QXcbConnection: XCB error: 9 (BadDrawable), sequence: 806, resource id: 63, major code: 14 (GetGeometry), minor code: 0 Feb 25 17:18:48 radio plasmashell[2436]: kf.plasma.quick: Applet preload policy set to 1 Feb 25 17:18:49 radio org_kde_powerdevil[2507]: org.kde.powerdevil: org.kde.powerdevil.chargethresholdhelper.getthreshold failed "Charge thresholds are not supported by the kernel for this hardware" Feb 25 17:18:49 radio org_kde_powerdevil[2507]: org.kde.powerdevil: org.kde.powerdevil.backlighthelper.brightness failed Feb 25 17:18:49 radio systemd[2203]: plasma-powerdevil.service: start operation timed out. Terminating. Feb 25 17:18:49 radio systemd[2203]: plasma-powerdevil.service: Failed with result 'timeout'. Feb 25 17:18:49 radio systemd[2203]: Failed to start plasma-powerdevil.service - Powerdevil. Feb 25 17:18:49 radio systemd[2203]: Reached target plasma-workspace.target - KDE Plasma Workspace. Feb 25 17:18:49 radio systemd[2203]: Reached target graphical-session.target - Current graphical user session. Feb 25 17:18:49 radio systemd[2203]: Reached target plasma-workspace-x11.target. Feb 25 17:18:49 radio systemd[2203]: Starting app-chromium@autostart.service - Chromium Web Browser... Feb 25 17:18:49 radio systemd[2203]: Starting app-kaccess@autostart.service - Accessibility... Feb 25 17:18:49 radio systemd[2203]: Starting app-klipper@autostart.service - Klipper... Feb 25 17:18:49 radio systemd[2203]: Starting app-konqy_preload@autostart.service - Konqueror preloading during desktop environment startup... Feb 25 17:18:49 radio systemd[2203]: Starting app-kup\x2ddaemon@autostart.service - Kup... Feb 25 17:18:49 radio systemd[2203]: Starting app-onboard\x2dautostart@autostart.service - Onboard... Feb 25 17:18:49 radio systemd[2203]: Starting app-org.kde.discover.notifier@autostart.service - Discover... Feb 25 17:18:49 radio systemd[2203]: Starting app-org.kde.kdeconnect.daemon@autostart.service - KDE Connect... Feb 25 17:18:49 radio systemd[2203]: Starting app-snap\x2duserd\x2dautostart@autostart.service - Snap user application autostart helper... Feb 25 17:18:49 radio systemd[2203]: Starting plasma-ksplash-ready.service - KSplash "ready" Stage... Feb 25 17:18:49 radio systemd[2203]: Starting plasma-restoresession.service - KDE Session Restoration... Feb 25 17:18:50 radio systemd[2203]: app-onboard\x2dautostart@autostart.service: Skipped due to 'exec-condition'. Feb 25 17:18:50 radio systemd[2203]: Condition check resulted in app-onboard\x2dautostart@autostart.service - Onboard being skipped. Feb 25 17:18:50 radio systemd[2203]: Started app-chromium@autostart.service - Chromium Web Browser. Feb 25 17:18:50 radio systemd[2203]: Started app-snap\x2duserd\x2dautostart@autostart.service - Snap user application autostart helper. Feb 25 17:18:50 radio systemd[2203]: Started app-kaccess@autostart.service - Accessibility. Feb 25 17:18:50 radio systemd[2203]: plasma-powerdevil.service: Scheduled restart job, restart counter is at 1. Feb 25 17:18:50 radio systemd[2203]: Stopped plasma-powerdevil.service - Powerdevil. Feb 25 17:18:50 radio systemd[2203]: Starting plasma-powerdevil.service - Powerdevil... Feb 25 17:18:50 radio systemd[2203]: Started app-org.kde.discover.notifier@autostart.service - Discover. Feb 25 17:18:50 radio systemd[2203]: Started app-org.kde.kdeconnect.daemon@autostart.service - KDE Connect. Feb 25 17:18:50 radio systemd[2203]: app-klipper@autostart.service: Skipped due to 'exec-condition'. Feb 25 17:18:50 radio systemd[2203]: Condition check resulted in app-klipper@autostart.service - Klipper being skipped. Feb 25 17:18:50 radio systemd[2203]: app-konqy_preload@autostart.service: Skipped due to 'exec-condition'. Feb 25 17:18:50 radio systemd[2203]: Condition check resulted in app-konqy_preload@autostart.service - Konqueror preloading during desktop environment startup being skipped. Feb 25 17:18:50 radio systemd[2203]: Finished plasma-restoresession.service - KDE Session Restoration. Feb 25 17:18:50 radio systemd[2203]: Started app-kup\x2ddaemon@autostart.service - Kup. Feb 25 17:18:50 radio systemd[2203]: Reached target xdg-desktop-autostart.target - Startup of XDG autostart applications. Feb 25 17:18:50 radio systemd[2203]: Finished plasma-ksplash-ready.service - KSplash "ready" Stage. Feb 25 17:18:50 radio kaccess[2619]: Xlib XKB extension major= 1 minor= 0 Feb 25 17:18:50 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 25 17:18:50 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:51 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:51 radio go-librespot[2654]: go-librespot daemon starting... Feb 25 17:18:51 radio go-librespot[2658]: time="2026-02-25T17:18:51+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:51 radio go-librespot[2658]: time="2026-02-25T17:18:51+01:00" level=debug msg="app state loaded" Feb 25 17:18:51 radio go-librespot[2658]: time="2026-02-25T17:18:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:51 radio go-librespot[2658]: time="2026-02-25T17:18:51+01: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" Feb 25 17:18:51 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:51 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:51 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:51 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:51 radio kded5[2366]: Delayed initialization. Feb 25 17:18:51 radio dbus-daemon[750]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.7' (uid=0 pid=959 comm="/usr/sbin/NetworkManager --no-daemon") Feb 25 17:18:51 radio systemd[1]: Starting NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service... Feb 25 17:18:51 radio kded5[2366]: Reloading the khotkeys configuration Feb 25 17:18:51 radio kded5[2366]: Version 2 File! Feb 25 17:18:52 radio dbus-daemon[750]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Feb 25 17:18:52 radio systemd[1]: Started NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service. Feb 25 17:18:52 radio kaccess[2619]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:52 radio kaccess[2619]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:52 radio kaccess[2619]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:52 radio kaccess[2619]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:52 radio kaccess[2619]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:52 radio kded5[2366]: true Feb 25 17:18:52 radio kded5[2366]: Imported file "/usr/share/khotkeys/defaults.khotkeys" Feb 25 17:18:52 radio kded5[2366]: Imported file "/usr/share/khotkeys/kde32b1.khotkeys" Feb 25 17:18:52 radio kded5[2366]: Imported file "/usr/share/khotkeys/konqueror_gestures_kde321.khotkeys" Feb 25 17:18:52 radio kup-daemon[2634]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:52 radio kup-daemon[2634]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:52 radio kup-daemon[2634]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:52 radio kup-daemon[2634]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:52 radio kup-daemon[2634]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:53 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.kde.KScreen' unit='plasma-kscreen.service' requested by ':1.17' (uid=1000 pid=2436 comm="/usr/bin/plasmashell --no-respawn") Feb 25 17:18:53 radio systemd[2203]: Starting plasma-kscreen.service - KScreen... Feb 25 17:18:53 radio org_kde_powerdevil[2625]: org.kde.powerdevil: org.kde.powerdevil.chargethresholdhelper.getthreshold failed "Charge thresholds are not supported by the kernel for this hardware" Feb 25 17:18:53 radio org_kde_powerdevil[2625]: org.kde.powerdevil: org.kde.powerdevil.backlighthelper.brightness failed Feb 25 17:18:53 radio DiscoverNotifier[2622]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:53 radio dbus-daemon[750]: [system] Activating service name='org.kde.kded.smart' requested by ':1.32' (uid=1000 pid=2366 comm="/usr/bin/kded5") (using servicehelper) Feb 25 17:18:53 radio DiscoverNotifier[2622]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:53 radio DiscoverNotifier[2622]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:53 radio kaccess[2619]: X server XKB extension major= 1 minor= 0 Feb 25 17:18:53 radio DiscoverNotifier[2622]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:53 radio DiscoverNotifier[2622]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:53 radio kdeconnectd[2614]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:53 radio kdeconnectd[2614]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:53 radio kdeconnectd[2614]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:53 radio kwin_x11[2367]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 1080, resource id: 6291635, major code: 18 (ChangeProperty), minor code: 0 Feb 25 17:18:53 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.kde.KScreen' Feb 25 17:18:53 radio systemd[2203]: Started plasma-kscreen.service - KScreen. Feb 25 17:18:53 radio kdeconnectd[2614]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:53 radio kdeconnectd[2614]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:54 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Connected output 555 to CRTC 554 Feb 25 17:18:54 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Detected XRandR 1.6 Feb 25 17:18:54 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Event Base: 89 Feb 25 17:18:54 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Event Error: 147 Feb 25 17:18:54 radio kup-daemon[2634]: kup.daemon: "Kup is not enabled, enable it from the system settings module. You can do that by running kcmshell5 kup" Feb 25 17:18:54 radio kwin_x11[2367]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 1095, resource id: 48234501, major code: 18 (ChangeProperty), minor code: 0 Feb 25 17:18:54 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 25 17:18:54 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:54 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:54 radio go-librespot[2753]: go-librespot daemon starting... Feb 25 17:18:54 radio go-librespot[2754]: time="2026-02-25T17:18:54+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:54 radio go-librespot[2754]: time="2026-02-25T17:18:54+01:00" level=debug msg="app state loaded" Feb 25 17:18:54 radio go-librespot[2754]: time="2026-02-25T17:18:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:54 radio go-librespot[2754]: time="2026-02-25T17:18:54+01: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" Feb 25 17:18:54 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:54 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:54 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:54 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:54 radio dbus-daemon[750]: [system] Successfully activated service 'org.kde.kded.smart' Feb 25 17:18:54 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.bluez.obex' unit='obex.service' requested by ':1.9' (uid=1000 pid=2366 comm="/usr/bin/kded5") Feb 25 17:18:54 radio dbus-daemon[750]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.32' (uid=1000 pid=2366 comm="/usr/bin/kded5") Feb 25 17:18:54 radio dbus-daemon[750]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service not found. Feb 25 17:18:54 radio systemd[2203]: Starting obex.service - Bluetooth OBEX service... Feb 25 17:18:54 radio dbus-daemon[750]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.59' (uid=1000 pid=2622 comm="/usr/lib/arm-linux-gnueabihf/libexec/DiscoverNotif") Feb 25 17:18:54 radio obexd[2775]: OBEX daemon 5.66 Feb 25 17:18:54 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.bluez.obex' Feb 25 17:18:54 radio kded5[2366]: QDBusAbstractAdaptor: Cannot relay signal KDEDModule::moduleDeleted(KDEDModule*): Pointers are not supported: KDEDModule* Feb 25 17:18:54 radio kded5[2366]: Known activities: ("c2a277d2-a013-409a-8ad5-9f294061dbd1") Feb 25 17:18:54 radio kded5[2366]: kf.bluezqt: PendingCall Error: "Unit dbus-org.bluez.service not found." Feb 25 17:18:54 radio systemd[2203]: Started obex.service - Bluetooth OBEX service. Feb 25 17:18:54 radio systemd[1]: Starting packagekit.service - PackageKit Daemon... Feb 25 17:18:54 radio org_kde_powerdevil[2625]: org.kde.kscreen.dpms: DPMS extension not available Feb 25 17:18:54 radio kded5[2366]: kscreen.kded: PowerDevil SuspendSession action not available! Feb 25 17:18:55 radio PackageKit[2781]: daemon start Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: XRandR::setConfig Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Requested screen size is QSize(720, 576) Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Needed CRTCs: 1 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Actions to perform: Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: Priorities: true Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Output 555 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: Old: "0" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: New: "1" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Change Screen Size: false Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Disable outputs: false Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Change outputs: false Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Enable outputs: false Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: RRSetOutputPrimary Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: New priority: 1 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: XRandR::setConfig done! Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: RRNotify_OutputProperty (ignored) Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Timestamp: 129389 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Output: 555 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Property: _KDE_SCREEN_INDEX Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: State (newValue, Deleted): 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: RRNotify_OutputProperty (ignored) Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Timestamp: 129389 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Output: 555 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Property: _KDE_SCREEN_INDEX Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: State (newValue, Deleted): 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: RRNotify_OutputChange Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Timestamp: 105841 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Output: 555 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: CRTC: 554 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Mode: 556 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Rotation: "Rotate_0" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Connection: "Connected" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Subpixel Order: 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: RRScreenChangeNotify Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Timestamp: 105841 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Config_timestamp: 110284 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Window: 50331653 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Root: 544 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Rotation: "Rotate_0" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Size ID: 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Size: 720 576 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: SizeMM: 191 152 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: RRNotify_OutputChange Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Timestamp: 105841 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Output: 555 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: CRTC: 554 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Mode: 556 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Rotation: "Rotate_0" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Connection: "Connected" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xcb.helper: Subpixel Order: 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: XRandROutput 555 update Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: m_connected: 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: m_crtc XRandRCrtc(0x13e2eb0) Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: CRTC: 554 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: MODE: 556 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: Connection: 0 Feb 25 17:18:55 radio kwin_x11[2367]: kwin_platform_x11_standalone: Bogus refresh rate 0 Feb 25 17:18:55 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.digitalclock/contents/ui/DigitalClock.qml:534:9: QML Label: Binding loop detected for property "height" Feb 25 17:18:55 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.digitalclock/contents/ui/DigitalClock.qml:499:13: QML Label: Binding loop detected for property "height" Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Output 555 : connected = true , enabled = true Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: XRandROutput 555 update Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: m_connected: 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: m_crtc XRandRCrtc(0x13e2eb0) Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: CRTC: 554 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: MODE: 556 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: Connection: 0 Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Output 555 : connected = true , enabled = true Feb 25 17:18:55 radio systemd[2203]: plasma-powerdevil.service: start operation timed out. Terminating. Feb 25 17:18:55 radio systemd[2203]: plasma-powerdevil.service: Failed with result 'timeout'. Feb 25 17:18:55 radio systemd[2203]: Failed to start plasma-powerdevil.service - Powerdevil. Feb 25 17:18:55 radio systemd[2203]: plasma-powerdevil.service: Scheduled restart job, restart counter is at 2. Feb 25 17:18:55 radio systemd[2203]: Stopped plasma-powerdevil.service - Powerdevil. Feb 25 17:18:55 radio systemd[2203]: Starting plasma-powerdevil.service - Powerdevil... Feb 25 17:18:55 radio kscreen_backend_launcher[2701]: kscreen.xrandr: Emitting configChanged() Feb 25 17:18:55 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating service name='org.freedesktop.Notifications' requested by ':1.31' (uid=1000 pid=2614 comm="/usr/lib/arm-linux-gnueabihf/libexec/kdeconnectd") Feb 25 17:18:55 radio kded5[2366]: Registering ":1.33/StatusNotifierItem" to system tray Feb 25 17:18:56 radio plasmashell[2436]: Trying to use rootObject before initialization is completed, whilst using setInitializationDelayed. Forcing completion Feb 25 17:18:56 radio plasmashell[2436]: org.kde.plasma.kicker: Entry is not valid "preferred://browser" QSharedPointer(0x2feb318) Feb 25 17:18:56 radio plasmashell[2436]: org.kde.plasma.kicker: Entry is not valid "org.kde.kontact.desktop" QSharedPointer(0x2feb318) Feb 25 17:18:56 radio plasmashell[2436]: org.kde.plasma.kicker: Entry is not valid "ktp-contactlist.desktop" QSharedPointer(0x3107110) Feb 25 17:18:56 radio plasmashell[2436]: org.kde.plasma.kicker: Entry is not valid "preferred://browser" QSharedPointer(0x2fcc430) Feb 25 17:18:56 radio plasmashell[2436]: org.kde.plasma.kicker: Entry is not valid "org.kde.kontact.desktop" QSharedPointer(0x2fcc430) Feb 25 17:18:56 radio plasmashell[2436]: org.kde.plasma.kicker: Entry is not valid "ktp-contactlist.desktop" QSharedPointer(0x303e158) Feb 25 17:18:56 radio dbus-daemon[750]: [system] Successfully activated service 'org.freedesktop.PackageKit' Feb 25 17:18:56 radio systemd[1]: Started packagekit.service - PackageKit Daemon. Feb 25 17:18:56 radio dbus-daemon[750]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.63' (uid=1000 pid=2604 comm="/usr/lib/chromium/chromium --force-renderer-access") Feb 25 17:18:56 radio dbus-daemon[750]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service not found. Feb 25 17:18:57 radio org_kde_powerdevil[2799]: org.kde.powerdevil: org.kde.powerdevil.chargethresholdhelper.getthreshold failed "Charge thresholds are not supported by the kernel for this hardware" Feb 25 17:18:57 radio org_kde_powerdevil[2799]: org.kde.powerdevil: org.kde.powerdevil.backlighthelper.brightness failed Feb 25 17:18:57 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating service name='org.kde.kwalletd5' requested by ':1.37' (uid=1000 pid=2604 comm="/usr/lib/chromium/chromium --force-renderer-access") Feb 25 17:18:57 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:18:57 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:18:57 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 25 17:18:57 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:57 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:18:57 radio go-librespot[2846]: go-librespot daemon starting... Feb 25 17:18:57 radio go-librespot[2852]: time="2026-02-25T17:18:57+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:18:57 radio go-librespot[2852]: time="2026-02-25T17:18:57+01:00" level=debug msg="app state loaded" Feb 25 17:18:57 radio go-librespot[2852]: time="2026-02-25T17:18:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:18:57 radio go-librespot[2852]: time="2026-02-25T17:18:57+01: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" Feb 25 17:18:57 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:18:57 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:18:57 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.digitalclock/contents/ui/DigitalClock.qml:499:13: QML Label: Binding loop detected for property "height" Feb 25 17:18:57 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.digitalclock/contents/ui/DigitalClock.qml:534:9: QML Label: Binding loop detected for property "height" Feb 25 17:18:57 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.digitalclock/contents/ui/DigitalClock.qml:556:5: QML Label: Binding loop detected for property "height" Feb 25 17:18:58 radio org_kde_powerdevil[2799]: org.kde.kscreen.dpms: DPMS extension not available Feb 25 17:18:58 radio org.kde.kwalletd5[2844]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:58 radio org.kde.kwalletd5[2844]: libEGL warning: DRI2: failed to authenticate Feb 25 17:18:58 radio org.kde.kwalletd5[2844]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:18:58 radio org.kde.kwalletd5[2844]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:18:58 radio org.kde.kwalletd5[2844]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:18:58 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.kde.kwalletd5' Feb 25 17:18:59 radio systemd[2203]: Started plasma-powerdevil.service - Powerdevil. Feb 25 17:18:59 radio org_kde_powerdevil[2799]: org.kde.powerdevil: The profile "AC" tried to activate "DimDisplay" a non-existent action. This is usually due to an installation problem, a configuration problem, or because the action is not supported Feb 25 17:18:59 radio org_kde_powerdevil[2799]: org.kde.powerdevil: The profile "AC" tried to activate "DPMSControl" a non-existent action. This is usually due to an installation problem, a configuration problem, or because the action is not supported Feb 25 17:18:59 radio org_kde_powerdevil[2799]: org.kde.powerdevil: org.kde.powerdevil.chargethresholdhelper.getthreshold failed "Charge thresholds are not supported by the kernel for this hardware" Feb 25 17:19:00 radio plasmashell[2714]: QObject::connect: No such slot DesktopProtocol::_k_slotRedirection(KIO::Job *, QUrl) Feb 25 17:19:00 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:00 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:00 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.a11y.Bus' unit='at-spi-dbus-bus.service' requested by ':1.39' (uid=1000 pid=2604 comm="/usr/lib/chromium/chromium --force-renderer-access") Feb 25 17:19:00 radio systemd[2203]: Starting at-spi-dbus-bus.service - Accessibility services bus... Feb 25 17:19:00 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.a11y.Bus' Feb 25 17:19:00 radio systemd[2203]: Started at-spi-dbus-bus.service - Accessibility services bus. Feb 25 17:19:00 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 25 17:19:00 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:00 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:00 radio go-librespot[2936]: go-librespot daemon starting... Feb 25 17:19:00 radio go-librespot[2937]: time="2026-02-25T17:19:00+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:00 radio go-librespot[2937]: time="2026-02-25T17:19:00+01:00" level=debug msg="app state loaded" Feb 25 17:19:00 radio go-librespot[2937]: time="2026-02-25T17:19:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:00 radio go-librespot[2937]: time="2026-02-25T17:19:00+01: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" Feb 25 17:19:00 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:00 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:01 radio CRON[2944]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0) Feb 25 17:19:01 radio CRON[2945]: (root) CMD (/home/volumio/network-monitor.sh) Feb 25 17:19:01 radio CRON[2944]: pam_unix(cron:session): session closed for user root Feb 25 17:19:01 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.kscreen/contents/ui/main.qml:30:5: Unable to assign [undefined] to bool Feb 25 17:19:01 radio plasmashell[2436]: Cyclic dependency detected between "file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/global/Globals.qml" and "file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/NotificationHeader.qml" Feb 25 17:19:01 radio plasmashell[2436]: Cyclic dependency detected between "file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/global/Globals.qml" and "file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/ThumbnailStrip.qml" Feb 25 17:19:01 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.freedesktop.Notifications' Feb 25 17:19:01 radio at-spi-bus-launcher[2935]: dbus-daemon[2935]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=1000 pid=2604 comm="/usr/lib/chromium/chromium --force-renderer-access") Feb 25 17:19:01 radio systemd[2203]: Started app-org.chromium.Chromium-2604.scope. Feb 25 17:19:01 radio at-spi-bus-launcher[2935]: dbus-daemon[2935]: Successfully activated service 'org.a11y.atspi.Registry' Feb 25 17:19:01 radio at-spi-bus-launcher[2961]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry Feb 25 17:19:01 radio kwin_x11[2367]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 1382, resource id: 16777239, major code: 3 (GetWindowAttributes), minor code: 0 Feb 25 17:19:01 radio kwin_x11[2367]: qt.qpa.xcb: QXcbConnection: XCB error: 9 (BadDrawable), sequence: 1383, resource id: 16777239, major code: 14 (GetGeometry), minor code: 0 Feb 25 17:19:02 radio volumio[1778]: info: AutoStart - Plugin is starting Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioGetQueue Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::getQueue Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getQueue Feb 25 17:19:02 radio volumio[1778]: info: AutoStart - start playing Feb 25 17:19:02 radio volumio[1778]: info: AutoStart - start playing with no specific position Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPlay Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::play index 0 Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::play index undefined Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::startPlaybackTimer Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: info: [1772036342053] ControllerWebradio::clearAddPlayTrack Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand stop Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand stop took 35 milliseconds Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand clear Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand clear took 6 milliseconds Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand load "http://mp3.stream.tb-group.fm/tb.mp3" Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces system playlist update Feb 25 17:19:02 radio volumio[1778]: info: Ignoring MPD Status Update Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces system playlist update Feb 25 17:19:02 radio volumio[1778]: info: Ignoring MPD Status Update Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces system playlist update Feb 25 17:19:02 radio volumio[1778]: info: Ignoring MPD Status Update Feb 25 17:19:02 radio volumio[1778]: error: updateQueue error: null Feb 25 17:19:02 radio volumio[1778]: error: updateQueue error: null Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand add "http://mp3.stream.tb-group.fm/tb.mp3" Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 48ms Feb 25 17:19:02 radio systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully. Feb 25 17:19:02 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.freedesktop.portal.Desktop' unit='xdg-desktop-portal.service' requested by ':1.36' (uid=1000 pid=2604 comm="/usr/lib/chromium/chromium --force-renderer-access") Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 112ms Feb 25 17:19:02 radio volumio[1778]: error: updateQueue error: null Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces system playlist update Feb 25 17:19:02 radio volumio[1778]: info: Ignoring MPD Status Update Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 119ms Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand add "http://mp3.stream.tb-group.fm/tb.mp3" took 116 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand play Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces system playlist update Feb 25 17:19:02 radio volumio[1778]: info: Ignoring MPD Status Update Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces system playlist update Feb 25 17:19:02 radio volumio[1778]: info: Ignoring MPD Status Update Feb 25 17:19:02 radio systemd[2203]: Starting xdg-desktop-portal.service - Portal service... Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 60ms Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand play took 72 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 71ms Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 70ms Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces state update: player Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::getState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand status Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces state update: player Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::getState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand status Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces state update: player Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::getState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand status Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces state update: player Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::getState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand status Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand status took 89 milliseconds Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand status took 80 milliseconds Feb 25 17:19:02 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.freedesktop.portal.Documents' unit='xdg-document-portal.service' requested by ':1.42' (uid=1000 pid=2965 comm="/usr/libexec/xdg-desktop-portal") Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces state update: player Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::getState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand status Feb 25 17:19:02 radio volumio[1778]: info: Feb 25 17:19:02 radio volumio[1778]: ---------------------------- MPD announces state update: player Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::getState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand status Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand status took 141 milliseconds Feb 25 17:19:02 radio systemd[2203]: Starting xdg-document-portal.service - flatpak document portal service... Feb 25 17:19:02 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.networkmanagement/contents/ui/main.qml:95: TypeError: Cannot read property 'airplaneModeAvailable' of null Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand status took 211 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand clearerror took 171 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand clearerror took 170 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand playlistinfo took 125 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand playlistinfo took 124 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand status took 109 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand status took 85 milliseconds Feb 25 17:19:02 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.freedesktop.impl.portal.PermissionStore' unit='xdg-permission-store.service' requested by ':1.43' (uid=1000 pid=2972 comm="/usr/libexec/xdg-document-portal") Feb 25 17:19:02 radio systemd[2203]: Starting xdg-permission-store.service - sandboxed app permission store... Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseTrackInfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseTrackInfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseState Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::servicePushState Feb 25 17:19:02 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore' Feb 25 17:19:02 radio systemd[2203]: Started xdg-permission-store.service - sandboxed app permission store. Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tb.mp3","artist":null,"album":null,"uri":"http://mp3.stream.tb-group.fm/tb.mp3","trackType":"mp3"} Feb 25 17:19:02 radio volumio[1778]: verbose: CURRENT POSITION 0 Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState stateService stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState currentStatus stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: No code Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::servicePushState Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio systemd[2203]: Started xdg-document-portal.service - flatpak document portal service. Feb 25 17:19:02 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.freedesktop.portal.Documents' Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tb.mp3","artist":null,"album":null,"uri":"http://mp3.stream.tb-group.fm/tb.mp3","trackType":"mp3"} Feb 25 17:19:02 radio volumio[1778]: verbose: CURRENT POSITION 0 Feb 25 17:19:02 radio xdg-document-portal[2972]: Ignoring invalid max threads value 4294967295 > max (100000). Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState stateService stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState currentStatus stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: No code Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 453ms Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 423ms Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand clearerror took 261 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand clearerror took 189 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand playlistinfo took 137 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand playlistinfo took 139 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand playlistinfo took 136 milliseconds Feb 25 17:19:02 radio volumio[1778]: info: sendMpdCommand playlistinfo took 136 milliseconds Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseTrackInfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseTrackInfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseTrackInfo Feb 25 17:19:02 radio volumio[1778]: verbose: ControllerMpd::parseTrackInfo Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::servicePushState Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tb.mp3","artist":null,"album":null,"uri":"http://mp3.stream.tb-group.fm/tb.mp3","trackType":"mp3"} Feb 25 17:19:02 radio volumio[1778]: verbose: CURRENT POSITION 0 Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState stateService stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState currentStatus stop Feb 25 17:19:02 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.gtk' unit='xdg-desktop-portal-gtk.service' requested by ':1.42' (uid=1000 pid=2965 comm="/usr/libexec/xdg-desktop-portal") Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: No code Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::servicePushState Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tb.mp3","artist":null,"album":null,"uri":"http://mp3.stream.tb-group.fm/tb.mp3","trackType":"mp3"} Feb 25 17:19:02 radio volumio[1778]: verbose: CURRENT POSITION 0 Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState stateService stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState currentStatus stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: No code Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::servicePushState Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tb.mp3","artist":null,"album":null,"uri":"http://mp3.stream.tb-group.fm/tb.mp3","trackType":"mp3"} Feb 25 17:19:02 radio volumio[1778]: verbose: CURRENT POSITION 0 Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState stateService stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState currentStatus stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: No code Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: ControllerMpd::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::servicePushState Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: CorePlayQueue::getTrack 0 Feb 25 17:19:02 radio volumio[1778]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tb.mp3","artist":null,"album":null,"uri":"http://mp3.stream.tb-group.fm/tb.mp3","trackType":"mp3"} Feb 25 17:19:02 radio volumio[1778]: verbose: CURRENT POSITION 0 Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState stateService stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::syncState currentStatus stop Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: No code Feb 25 17:19:02 radio volumio[1778]: info: CoreStateMachine::pushState Feb 25 17:19:02 radio volumio[1778]: info: CoreCommandRouter::volumioPushState Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 498ms Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 476ms Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 372ms Feb 25 17:19:02 radio volumio[1778]: info: ------------------------------ 372ms Feb 25 17:19:02 radio systemd[2203]: Starting xdg-desktop-portal-gtk.service - Portal service (GTK/GNOME implementation)... Feb 25 17:19:03 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.freedesktop.impl.portal.desktop.gtk' Feb 25 17:19:03 radio systemd[2203]: Started xdg-desktop-portal-gtk.service - Portal service (GTK/GNOME implementation). Feb 25 17:19:03 radio rtkit-daemon[2222]: Supervising 1 threads of 1 processes of 1 users. Feb 25 17:19:03 radio rtkit-daemon[2222]: Supervising 1 threads of 1 processes of 1 users. Feb 25 17:19:03 radio rtkit-daemon[2222]: Supervising 1 threads of 1 processes of 1 users. Feb 25 17:19:03 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.kde' unit='plasma-xdg-desktop-portal-kde.service' requested by ':1.42' (uid=1000 pid=2965 comm="/usr/libexec/xdg-desktop-portal") Feb 25 17:19:03 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:03 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:03 radio systemd[2203]: Starting plasma-xdg-desktop-portal-kde.service - Xdg Desktop Portal For KDE... Feb 25 17:19:03 radio xdg-desktop-portal-kde[3001]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:19:03 radio xdg-desktop-portal-kde[3001]: libEGL warning: DRI2: failed to authenticate Feb 25 17:19:03 radio xdg-desktop-portal-kde[3001]: libEGL warning: DRI3: Screen seems not DRI3 capable Feb 25 17:19:03 radio xdg-desktop-portal-kde[3001]: MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER) Feb 25 17:19:03 radio xdg-desktop-portal-kde[3001]: libEGL warning: egl: failed to create dri2 screen Feb 25 17:19:03 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 25 17:19:03 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:04 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:04 radio go-librespot[3012]: go-librespot daemon starting... Feb 25 17:19:04 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.freedesktop.impl.portal.desktop.kde' Feb 25 17:19:04 radio systemd[2203]: Started plasma-xdg-desktop-portal-kde.service - Xdg Desktop Portal For KDE. Feb 25 17:19:04 radio go-librespot[3014]: time="2026-02-25T17:19:04+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:04 radio go-librespot[3014]: time="2026-02-25T17:19:04+01:00" level=debug msg="app state loaded" Feb 25 17:19:04 radio go-librespot[3014]: time="2026-02-25T17:19:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:04 radio go-librespot[3014]: time="2026-02-25T17:19:04+01: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" Feb 25 17:19:04 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:04 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:04 radio xdg-desktop-portal[2965]: pw.conf: can't load config client.conf: No such file or directory Feb 25 17:19:04 radio xdg-desktop-portal[2965]: pw.conf: can't load config client.conf: No such file or directory Feb 25 17:19:04 radio xdg-desktop-por[2965]: Failed connect to PipeWire: Couldn't create PipeWire context Feb 25 17:19:04 radio dbus-daemon[2221]: [session uid=1000 pid=2221] Successfully activated service 'org.freedesktop.portal.Desktop' Feb 25 17:19:04 radio systemd[2203]: Started xdg-desktop-portal.service - Portal service. Feb 25 17:19:04 radio xdg-desktop-portal-kde[3001]: xdp-kde-settings: Namespace "org.freedesktop.appearance" is not supported Feb 25 17:19:04 radio plasmashell[2436]: QFont::setPointSizeF: Point size <= 0 (0.000000), must be greater than 0 Feb 25 17:19:06 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:06 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:07 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 25 17:19:07 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:07 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:07 radio go-librespot[3039]: go-librespot daemon starting... Feb 25 17:19:07 radio go-librespot[3040]: time="2026-02-25T17:19:07+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:07 radio go-librespot[3040]: time="2026-02-25T17:19:07+01:00" level=debug msg="app state loaded" Feb 25 17:19:07 radio go-librespot[3040]: time="2026-02-25T17:19:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:07 radio go-librespot[3040]: time="2026-02-25T17:19:07+01: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" Feb 25 17:19:07 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:07 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:08 radio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:08 radio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 17:19:08 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:09 radio volumio[1778]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 25 17:19:09 radio PackageKit[2781]: get-updates transaction /511_bbcecceb from uid 1000 finished with success after 12296ms Feb 25 17:19:09 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:09 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:09 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:09 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.battery/contents/ui/CompactRepresentation.qml:61:17: Unable to assign [undefined] to int Feb 25 17:19:09 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:09 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:09 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:09 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:09 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:10 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:10 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 25 17:19:10 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:10 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:10 radio go-librespot[3046]: go-librespot daemon starting... Feb 25 17:19:10 radio go-librespot[3047]: time="2026-02-25T17:19:10+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:10 radio go-librespot[3047]: time="2026-02-25T17:19:10+01:00" level=debug msg="app state loaded" Feb 25 17:19:10 radio go-librespot[3047]: time="2026-02-25T17:19:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:11 radio go-librespot[3047]: time="2026-02-25T17:19:10+01: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" Feb 25 17:19:11 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:11 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:11 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/PlaceholderMessage.qml:238:5: QML Heading: Binding loop detected for property "verticalAlignment" Feb 25 17:19:11 radio volumio[1778]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Feb 25 17:19:12 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 25 17:19:12 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:12 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::volumioGetVisibleSources Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::volumioGetState Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::volumioGetQueue Feb 25 17:19:13 radio volumio[1778]: info: CoreStateMachine::getQueue Feb 25 17:19:13 radio volumio[1778]: info: CorePlayQueue::getQueue Feb 25 17:19:13 radio volumio[1778]: info: Listing playlists Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 25 17:19:13 radio volumio[1778]: info: Received Get System Info Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 17:19:13 radio volumio[1778]: info: Discovery: Getting this device information Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::volumioGetState Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::volumioGetState Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 25 17:19:13 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 25 17:19:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 25 17:19:14 radio volumio[1778]: info: Received Get System Info Feb 25 17:19:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 17:19:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 17:19:14 radio volumio[1778]: info: Discovery: Getting this device information Feb 25 17:19:14 radio volumio[1778]: info: CoreCommandRouter::volumioGetState Feb 25 17:19:14 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 17:19:14 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 25 17:19:14 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:14 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:14 radio go-librespot[3054]: go-librespot daemon starting... Feb 25 17:19:14 radio go-librespot[3055]: time="2026-02-25T17:19:14+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:14 radio go-librespot[3055]: time="2026-02-25T17:19:14+01:00" level=debug msg="app state loaded" Feb 25 17:19:14 radio go-librespot[3055]: time="2026-02-25T17:19:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:14 radio go-librespot[3055]: time="2026-02-25T17:19:14+01: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" Feb 25 17:19:14 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:14 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:15 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:15 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:15 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 25 17:19:16 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:36:5: Unable to assign [undefined] to bool Feb 25 17:19:16 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:35:5: Unable to assign [undefined] to bool Feb 25 17:19:16 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:36:5: Unable to assign [undefined] to bool Feb 25 17:19:16 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:35:5: Unable to assign [undefined] to bool Feb 25 17:19:16 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/ExpandableListItem.qml:291: TypeError: Cannot read property 'enabled' of null Feb 25 17:19:16 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:36:5: Unable to assign [undefined] to bool Feb 25 17:19:16 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:35:5: Unable to assign [undefined] to bool Feb 25 17:19:17 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:36:5: Unable to assign [undefined] to bool Feb 25 17:19:17 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:35:5: Unable to assign [undefined] to bool Feb 25 17:19:17 radio plasmashell[2436]: file:///usr/lib/arm-linux-gnueabihf/qt5/qml/org/kde/plasma/extras/ExpandableListItem.qml:291: TypeError: Cannot read property 'enabled' of null Feb 25 17:19:17 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:36:5: Unable to assign [undefined] to bool Feb 25 17:19:17 radio plasmashell[2436]: file:///usr/share/plasma/plasmoids/org.kde.plasma.devicenotifier/contents/ui/DeviceItem.qml:35:5: Unable to assign [undefined] to bool Feb 25 17:19:17 radio plasmashell[2436]: org.kde.plasma.pulseaudio: No object for name "alsa_output.platform-fe00b840.mailbox.stereo-fallback.2.monitor" Feb 25 17:19:17 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 25 17:19:17 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:17 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:17 radio go-librespot[3081]: go-librespot daemon starting... Feb 25 17:19:17 radio go-librespot[3082]: time="2026-02-25T17:19:17+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:17 radio go-librespot[3082]: time="2026-02-25T17:19:17+01:00" level=debug msg="app state loaded" Feb 25 17:19:17 radio go-librespot[3082]: time="2026-02-25T17:19:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:17 radio go-librespot[3082]: time="2026-02-25T17:19:17+01: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" Feb 25 17:19:17 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:17 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:18 radio chromium[2604]: [2604:2797:0225/171918.051452:ERROR:google_apis/gcm/engine/registration_request.cc:275] Registration URL fetching failed. Feb 25 17:19:18 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:18 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:20 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 25 17:19:20 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:20 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:20 radio go-librespot[3088]: go-librespot daemon starting... Feb 25 17:19:20 radio go-librespot[3089]: time="2026-02-25T17:19:20+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:20 radio go-librespot[3089]: time="2026-02-25T17:19:20+01:00" level=debug msg="app state loaded" Feb 25 17:19:20 radio go-librespot[3089]: time="2026-02-25T17:19:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:20 radio go-librespot[3089]: time="2026-02-25T17:19:20+01: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" Feb 25 17:19:20 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:20 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:21 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 25 17:19:21 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:21 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:22 radio plasmashell[2436]: QLockFile: Lock file '/home/volumio/.cache/plasma-svgelements.lock' has a modification time in the future Feb 25 17:19:23 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 25 17:19:23 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:24 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:24 radio go-librespot[3096]: go-librespot daemon starting... Feb 25 17:19:24 radio go-librespot[3097]: time="2026-02-25T17:19:24+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:24 radio go-librespot[3097]: time="2026-02-25T17:19:24+01:00" level=debug msg="app state loaded" Feb 25 17:19:24 radio go-librespot[3097]: time="2026-02-25T17:19:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:24 radio go-librespot[3097]: time="2026-02-25T17:19:24+01: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" Feb 25 17:19:24 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:24 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:24 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:24 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:27 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="LuiseUndBoerniHaus" Feb 25 17:19:27 radio wpa_supplicant[983]: wlan0: Trying to associate with dc:39:6f:2a:6c:39 (SSID='LuiseUndBoerniHaus' freq=2452 MHz) Feb 25 17:19:27 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 25 17:19:27 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:27 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:27 radio go-librespot[3117]: go-librespot daemon starting... Feb 25 17:19:27 radio go-librespot[3118]: time="2026-02-25T17:19:27+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:27 radio go-librespot[3118]: time="2026-02-25T17:19:27+01:00" level=debug msg="app state loaded" Feb 25 17:19:27 radio go-librespot[3118]: time="2026-02-25T17:19:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:27 radio go-librespot[3118]: time="2026-02-25T17:19:27+01: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" Feb 25 17:19:27 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:27 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:27 radio wpa_supplicant[983]: wlan0: Associated with dc:39:6f:2a:6c:39 Feb 25 17:19:27 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 25 17:19:27 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Feb 25 17:19:27 radio dhcpcd[872]: wlan0: carrier acquired Feb 25 17:19:27 radio dhcpcd[872]: wlan0: connected to Access Point: LuiseUndBoerniHaus Feb 25 17:19:27 radio wpa_supplicant[983]: wlan0: WPA: Key negotiation completed with dc:39:6f:2a:6c:39 [PTK=CCMP GTK=TKIP] Feb 25 17:19:27 radio wpa_supplicant[983]: wlan0: CTRL-EVENT-CONNECTED - Connection to dc:39:6f:2a:6c:39 completed [id=0 id_str=] Feb 25 17:19:27 radio dhcpcd[872]: wlan0: IAID dd:99:50:ff Feb 25 17:19:27 radio dhcpcd[872]: wlan0: adding address fe80::da3a:ddff:fe99:50ff Feb 25 17:19:27 radio dhcpcd[872]: ipv6_addaddr1: Permission denied Feb 25 17:19:27 radio dhcpcd[872]: wlan0: carrier lost - roaming Feb 25 17:19:27 radio dhcpcd[872]: wlan0: carrier lost - roaming Feb 25 17:19:27 radio dhcpcd[872]: wlan0: carrier acquired Feb 25 17:19:27 radio dhcpcd[872]: wlan0: IAID dd:99:50:ff Feb 25 17:19:27 radio dhcpcd[872]: wlan0: soliciting an IPv6 router Feb 25 17:19:27 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:27 radio volumio[1778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:29 radio dhcpcd[872]: wlan0: rebinding lease of 192.168.0.21 Feb 25 17:19:29 radio dhcpcd[872]: wlan0: probing address 192.168.0.21/24 Feb 25 17:19:30 radio chrome[2604]: [2604:2792:0225/171930.123636:INFO:chrome/browser/extensions/extension_garbage_collector.cc:188] Garbage collection for extensions on file thread is complete. Feb 25 17:19:30 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 25 17:19:30 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:30 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:30 radio go-librespot[3144]: go-librespot daemon starting... Feb 25 17:19:30 radio go-librespot[3145]: time="2026-02-25T17:19:30+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:30 radio go-librespot[3145]: time="2026-02-25T17:19:30+01:00" level=debug msg="app state loaded" Feb 25 17:19:30 radio volumio[1778]: info: Initializing connection to go-librespot Websocket Feb 25 17:19:30 radio go-librespot[3145]: time="2026-02-25T17:19:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:30 radio go-librespot[3145]: time="2026-02-25T17:19:30+01:00" level=debug msg="new websocket client" Feb 25 17:19:30 radio go-librespot[3145]: time="2026-02-25T17:19:30+01: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" Feb 25 17:19:30 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:30 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:30 radio volumio[1778]: info: Connection to go-librespot Websocket established Feb 25 17:19:30 radio volumio[1778]: info: Connection to go-librespot Websocket closed Feb 25 17:19:32 radio volumio[1778]: info: Preload queue cleared Feb 25 17:19:32 radio volumio[1778]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 25 17:19:32 radio volumio[1778]: info: CoreStateMachine::ClearQueue Feb 25 17:19:32 radio volumio[1778]: info: CoreStateMachine::stop Feb 25 17:19:32 radio volumio[1778]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 17:19:32 radio volumio[1778]: info: CorePlayQueue::clearPlayQueue Feb 25 17:19:32 radio volumio[1778]: info: CorePlayQueue::saveQueue Feb 25 17:19:32 radio volumio[1778]: info: CoreCommandRouter::volumioPushQueue Feb 25 17:19:32 radio volumio[1778]: info: CoreStateMachine::addQueueItems Feb 25 17:19:32 radio volumio[1778]: info: CorePlayQueue::addQueueItems Feb 25 17:19:32 radio volumio[1778]: info: Preload queue cleared Feb 25 17:19:32 radio volumio[1778]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s315835 Feb 25 17:19:32 radio volumio[1778]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 25 17:19:33 radio volumio[1778]: info: Getting Spotify volume Feb 25 17:19:33 radio volumio[1778]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 17:19:33 radio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 25 17:19:33 radio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:33 radio volumio[1778]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 17:19:33 radio volumio[1778]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 25 17:19:33 radio volumio[1778]: errno: -111, Feb 25 17:19:33 radio volumio[1778]: code: 'ECONNREFUSED', Feb 25 17:19:33 radio volumio[1778]: syscall: 'connect', Feb 25 17:19:33 radio volumio[1778]: address: '127.0.0.1', Feb 25 17:19:33 radio volumio[1778]: port: 9879, Feb 25 17:19:33 radio volumio[1778]: response: undefined Feb 25 17:19:33 radio volumio[1778]: } Feb 25 17:19:33 radio volumio[1778]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 17:19:33 radio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 17:19:33 radio go-librespot[3151]: go-librespot daemon starting... Feb 25 17:19:33 radio go-librespot[3155]: time="2026-02-25T17:19:33+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 17:19:33 radio go-librespot[3155]: time="2026-02-25T17:19:33+01:00" level=debug msg="app state loaded" Feb 25 17:19:33 radio go-librespot[3155]: time="2026-02-25T17:19:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 17:19:33 radio go-librespot[3155]: time="2026-02-25T17:19:33+01: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" Feb 25 17:19:33 radio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 17:19:33 radio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 17:19:34 radio dhcpcd[872]: wlan0: leased 192.168.0.21 for 86400 seconds Feb 25 17:19:34 radio avahi-daemon[748]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.21. Feb 25 17:19:34 radio avahi-daemon[748]: New relevant interface wlan0.IPv4 for mDNS. Feb 25 17:19:34 radio dhcpcd[872]: wlan0: adding route to 192.168.0.0/24 Feb 25 17:19:34 radio dhcpcd[872]: wlan0: adding default route via 192.168.0.1 Feb 25 17:19:34 radio avahi-daemon[748]: Registering new address record for 192.168.0.21 on wlan0.IPv4. Feb 25 17:19:34 radio systemd[1]: welcome.service: Deactivated successfully. Feb 25 17:19:34 radio systemd[1]: Stopped welcome.service - Show a welcome message on console. Feb 25 17:19:34 radio systemd[1]: Stopping welcome.service - Show a welcome message on console... Feb 25 17:19:34 radio systemd[1]: Starting welcome.service - Show a welcome message on console... Feb 25 17:19:34 radio welcome[3180]: Resolved ip:[1] 192.168.0.21 Feb 25 17:19:34 radio systemd[1]: Finished welcome.service - Show a welcome message on console. Feb 25 17:19:34 radio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Feb 25 17:19:35 radio ntpd[1076]: IO: Listen normally on 4 wlan0 192.168.0.21:123 Feb 25 17:19:35 radio ntpd[1076]: IO: new interface(s) found: waking up resolver Feb 25 17:19:35 radio ntpd[1076]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Feb 25 17:19:35 radio ntpd[1076]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Feb 25 17:19:35 radio ntpd[1076]: DNS: Pool taking: 194.59.205.229 Feb 25 17:19:35 radio ntpd[1076]: DNS: Pool taking: 77.42.16.222 Feb 25 17:19:35 radio ntpd[1076]: DNS: Pool taking: 172.104.134.72 Feb 25 17:19:35 radio ntpd[1076]: DNS: Pool taking: 77.90.40.94 Feb 25 17:19:35 radio ntpd[1076]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Feb 25 17:19:36 radio ntpd[1076]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Feb 25 17:19:36 radio ntpd[1076]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 93.241.86.156 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 217.91.44.17 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 116.203.218.109 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 31.209.85.243 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 2a02:8106:21:9400::2 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 2001:638:504:2000::37 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 2003:a:87f:c37c::8 Feb 25 17:19:36 radio ntpd[1076]: DNS: Pool taking: 2001:638:a000:1123:123::3 Feb 25 17:19:36 radio ntpd[1076]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Feb 25 17:19:36 radio sudo[3213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 17:18' Feb 25 17:19:36 radio sudo[3213]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"