Dec 15 15:24:15 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Dec 15 15:24:15 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Dec 15 15:24:15 volumio systemd[1]: setdatetime-helper.service: Consumed 1.691s CPU time.
Dec 15 15:24:15 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service...
Dec 15 15:24:15 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems...
Dec 15 15:24:15 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats.
Dec 15 15:24:15 volumio systemd[1]: e2scrub_all.service: Deactivated successfully.
Dec 15 15:24:15 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems.
Dec 15 15:24:15 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully.
Dec 15 15:24:15 volumio nmbd[1054]: [2025/12/15 15:24:15.298106, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Dec 15 15:24:15 volumio nmbd[1054]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.178.106 for name WORKGROUP<1d>.
Dec 15 15:24:15 volumio nmbd[1054]: This response was from IP 192.168.178.64, reporting an IP address of 192.168.178.64.
Dec 15 15:24:15 volumio smbd[1107]: [2025/12/15 15:24:15.426205, 0] ../../source3/smbd/server.c:1741(main)
Dec 15 15:24:15 volumio smbd[1107]: smbd version 4.17.8-Raspbian started.
Dec 15 15:24:15 volumio smbd[1107]: Copyright Andrew Tridgell and the Samba Team 1992-2022
Dec 15 15:24:15 volumio winbindd[1071]: [2025/12/15 15:24:15.615773, 0] ../../source3/winbindd/winbindd_idmap.c:372(wb_parent_idmap_setup_lookupname_done)
Dec 15 15:24:15 volumio winbindd[1071]: wb_parent_idmap_setup_lookupname_done: Lookup domain name 'VOLUMIO' failed 'NT_STATUS_IO_TIMEOUT'
Dec 15 15:24:15 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully.
Dec 15 15:24:15 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service.
Dec 15 15:24:15 volumio systemd[1]: Started smbd.service - Samba SMB Daemon.
Dec 15 15:24:15 volumio ntpd[869]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101
Dec 15 15:24:15 volumio ntpd[869]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101
Dec 15 15:24:15 volumio ntpd[869]: DNS: Pool taking: 158.180.28.150
Dec 15 15:24:15 volumio ntpd[869]: DNS: Pool skipping: 93.241.86.156
Dec 15 15:24:15 volumio ntpd[869]: DNS: Pool taking: 80.153.195.191
Dec 15 15:24:15 volumio ntpd[869]: DNS: Pool taking: 129.70.132.35
Dec 15 15:24:15 volumio ntpd[869]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8
Dec 15 15:24:16 volumio python[846]: 🚀 RFID Web Admin gestartet auf Port 5001
Dec 15 15:24:16 volumio python[846]: * Serving Flask app 'rfid_web'
Dec 15 15:24:16 volumio python[846]: * Debug mode: off
Dec 15 15:24:16 volumio python[846]: WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
Dec 15 15:24:16 volumio python[846]: * Running on all addresses (0.0.0.0)
Dec 15 15:24:16 volumio python[846]: * Running on http://127.0.0.1:5001
Dec 15 15:24:16 volumio python[846]: * Running on http://192.168.178.106:5001
Dec 15 15:24:16 volumio python[846]: Press CTRL+C to quit
Dec 15 15:24:16 volumio ntpd[869]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101
Dec 15 15:24:16 volumio ntpd[869]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101
Dec 15 15:24:16 volumio ntpd[869]: DNS: Pool taking: 212.132.97.26
Dec 15 15:24:16 volumio ntpd[869]: DNS: Pool taking: 45.157.234.88
Dec 15 15:24:16 volumio ntpd[869]: DNS: Pool skipping: 158.180.28.150
Dec 15 15:24:16 volumio ntpd[869]: DNS: Pool taking: 46.41.21.10
Dec 15 15:24:16 volumio ntpd[869]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8
Dec 15 15:24:16 volumio wireless.js[679]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless
Dec 15 15:24:16 volumio wireless.js[679]: WIRELESS.JS: Wired network status changed to: ---connected---
Dec 15 15:24:16 volumio wireless.js[679]: WIRELESS.JS: Wireless.js initializing wireless flow
Dec 15 15:24:16 volumio wireless.js[679]: WIRELESS.JS: Cleaning previous...
Dec 15 15:24:17 volumio bluealsa[888]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
Dec 15 15:24:17 volumio sudo[1155]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0
Dec 15 15:24:17 volumio sudo[1155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 15 15:24:17 volumio sudo[1155]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:17 volumio winbindd[1080]: [2025/12/15 15:24:17.321424, 0] ../../source3/winbindd/winbindd_dual.c:162(child_write_response)
Dec 15 15:24:17 volumio winbindd[1080]: Could not write result
Dec 15 15:24:17 volumio sudo[1158]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down
Dec 15 15:24:17 volumio sudo[1158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 15 15:24:17 volumio sudo[1158]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:18 volumio wireless.js[679]: WIRELESS.JS: Stopped aP
Dec 15 15:24:18 volumio sudo[1166]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Dec 15 15:24:18 volumio sudo[1166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:18 volumio sudo[1166]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:18 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Dec 15 15:24:18 volumio sudo[1168]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get
Dec 15 15:24:18 volumio sudo[1168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:18 volumio sudo[1168]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:18 volumio sudo[1176]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Dec 15 15:24:18 volumio sudo[1176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:18 volumio sudo[1176]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:18 volumio sudo[1178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan
Dec 15 15:24:18 volumio sudo[1178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:20 volumio volumio-remote-updater[675]: [2025-12-15 15:24:20] [info] asio async_connect error: asio.system:111 (Connection refused)
Dec 15 15:24:20 volumio volumio-remote-updater[675]: [2025-12-15 15:24:20] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected)
Dec 15 15:24:20 volumio volumio-remote-updater[675]: [2025-12-15 15:24:20] [error] handle_connect error: Connection refused
Dec 15 15:24:21 volumio sudo[1178]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:21 volumio wireless.js[679]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: DE
Dec 15 15:24:21 volumio sudo[1184]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Dec 15 15:24:21 volumio sudo[1184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:21 volumio sudo[1184]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:21 volumio sudo[1186]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE
Dec 15 15:24:21 volumio sudo[1186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:21 volumio sudo[1186]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:21 volumio wireless.js[679]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: DE
Dec 15 15:24:21 volumio wireless.js[679]: WIRELESS.JS: Single Network Mode: Wired network active, not starting wireless flow
Dec 15 15:24:21 volumio wireless.js[679]: WIRELESS.JS: Notified systemd about wireless ready
Dec 15 15:24:21 volumio systemd[1]: Started wireless.service - Wireless Services.
Dec 15 15:24:21 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Dec 15 15:24:21 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Dec 15 15:24:21 volumio systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen...
Dec 15 15:24:21 volumio systemd[1]: Starting rfid-player.service - RFID Card Player for Volumio...
Dec 15 15:24:21 volumio systemd[1]: Starting volumio-rfid-player.service - Volumio RFID Jukebox Player (Moode Prinzip)...
Dec 15 15:24:21 volumio systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker.
Dec 15 15:24:21 volumio systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up.
Dec 15 15:24:21 volumio systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen.
Dec 15 15:24:21 volumio systemd[1]: Received SIGRTMIN+21 from PID 282 (n/a).
Dec 15 15:24:21 volumio systemd[1]: Received SIGRTMIN+21 from PID 282 (n/a).
Dec 15 15:24:21 volumio systemd[1]: Started getty@tty1.service - Getty on tty1.
Dec 15 15:24:21 volumio systemd[1]: Reached target getty.target - Login Prompts.
Dec 15 15:24:22 volumio ntpd[869]: CLOCK: time stepped by 0.655801
Dec 15 15:24:22 volumio ntpd[869]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes
Dec 15 15:24:22 volumio volumio-cpu-tweak[1197]: Setting RT Priority for mpd
Dec 15 15:24:22 volumio volumio-cpu-tweak[1197]: Setting MPD Affinity
Dec 15 15:24:22 volumio volumio-cpu-tweak[1214]: pid 978's current affinity mask: f
Dec 15 15:24:22 volumio volumio-cpu-tweak[1214]: pid 978's new affinity mask: 3
Dec 15 15:24:22 volumio volumio-cpu-tweak[1197]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input
Dec 15 15:24:22 volumio volumio-cpu-tweak[1197]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance
Dec 15 15:24:22 volumio mpd[978]: 2025-12-15T15:24:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 15 15:24:22 volumio systemd[1]: volumio_cpu_tweak.service: Deactivated successfully.
Dec 15 15:24:24 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1.
Dec 15 15:24:24 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Dec 15 15:24:24 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Dec 15 15:24:24 volumio upmpdcli[1220]: Could not open config: /tmp/upmpdcli.conf
Dec 15 15:24:24 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:24:24 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Dec 15 15:24:25 volumio systemd[1]: Started bt-speaker-connect.service - Connect to Bluetooth Speaker on Boot.
Dec 15 15:24:25 volumio bash[1222]: Attempting to connect to 08:EB:ED:25:4F:D6
Dec 15 15:24:25 volumio bash[1222]: [NEW] Media /org/bluez/hci0
Dec 15 15:24:25 volumio bash[1222]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Dec 15 15:24:25 volumio bash[1222]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Dec 15 15:24:25 volumio bash[1222]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Dec 15 15:24:25 volumio bash[1222]: [NEW] Transport /org/bluez/hci0/dev_08_EB_ED_25_4F_D6/fd0
Dec 15 15:24:25 volumio bash[1222]: [NEW] Endpoint /org/bluez/hci0/dev_08_EB_ED_25_4F_D6/sep2
Dec 15 15:24:25 volumio bash[1222]: [NEW] Endpoint /org/bluez/hci0/dev_08_EB_ED_25_4F_D6/sep1
Dec 15 15:24:25 volumio bluetoothd[658]: Path / reserved for Adv Monitor app :1.10
Dec 15 15:24:25 volumio bash[1222]: AdvertisementMonitor path registered
Dec 15 15:24:25 volumio bash[1222]: [CHG] Device 08:EB:ED:25:4F:D6 ServicesResolved: yes
Dec 15 15:24:25 volumio bash[1222]: Connection successful
Dec 15 15:24:25 volumio bluetoothd[658]: Adv Monitor app :1.10 disconnected from D-Bus
Dec 15 15:24:25 volumio systemd[1]: bt-speaker-connect.service: Deactivated successfully.
Dec 15 15:24:27 volumio volumio[1193]: info: -------------------------------------------
Dec 15 15:24:27 volumio volumio[1193]: info: ----- Volumio3 ----
Dec 15 15:24:27 volumio volumio[1193]: info: -------------------------------------------
Dec 15 15:24:27 volumio volumio[1193]: info: ----- System startup ----
Dec 15 15:24:27 volumio volumio[1193]: info: -------------------------------------------
Dec 15 15:24:29 volumio volumio[1193]: info: MYVOLUMIO Environment detected
Dec 15 15:24:29 volumio volumio[1193]: info: Plugin folders cleanup
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning into folder /volumio/app/plugins/
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category audio_interface
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category miscellanea
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category music_service
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category plugins.json
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category system_controller
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category user_interface
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning into folder /data/plugins/
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category music_service
Dec 15 15:24:29 volumio volumio[1193]: info: Scanning category system_hardware
Dec 15 15:24:29 volumio volumio[1193]: info: Plugin folders cleanup completed
Dec 15 15:24:29 volumio volumio[1193]: info: -------------------------------------------
Dec 15 15:24:29 volumio volumio[1193]: info: ----- Core plugins startup ----
Dec 15 15:24:29 volumio volumio[1193]: info: -------------------------------------------
Dec 15 15:24:29 volumio volumio[1193]: info: Loading plugins from folder /volumio/app/plugins/
Dec 15 15:24:29 volumio volumio[1193]: info: Adding plugin upnp to MyMusic Plugins
Dec 15 15:24:29 volumio volumio[1193]: info: Adding plugin airplay_emulation to MyMusic Plugins
Dec 15 15:24:29 volumio volumio[1193]: info: Adding plugin upnp_browser to MyMusic Plugins
Dec 15 15:24:29 volumio volumio[1193]: info: Loading plugins from folder /data/plugins/
Dec 15 15:24:29 volumio volumio[1193]: info: Loading plugin "system"...
Dec 15 15:24:29 volumio volumio[1193]: info: Loading plugin "appearance"...
Dec 15 15:24:31 volumio volumio-remote-updater[675]: [2025-12-15 15:24:31] [connect] Successful connection
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "network"...
Dec 15 15:24:32 volumio volumio[1193]: info: Refreshing Cached IP Addresses
Dec 15 15:24:32 volumio sudo[1240]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 15 15:24:32 volumio sudo[1240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:32 volumio sudo[1240]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:32 volumio sudo[1238]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 15 15:24:32 volumio sudo[1238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:32 volumio sudo[1238]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "services"...
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "alsa_controller"...
Dec 15 15:24:32 volumio sudo[1247]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Dec 15 15:24:32 volumio sudo[1247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:32 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "wizard"...
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "networkfs"...
Dec 15 15:24:32 volumio volumio[1193]: info: Starting Udev Watcher for removable devices
Dec 15 15:24:32 volumio volumio[1193]: info: Ignoring mount for partition: boot
Dec 15 15:24:32 volumio volumio[1193]: info: Ignoring mount for partition: volumio
Dec 15 15:24:32 volumio volumio[1193]: info: Ignoring mount for partition: volumio_data
Dec 15 15:24:32 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "volumio_command_line_client"...
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "upnp"...
Dec 15 15:24:32 volumio volumio[1193]: info: [1765808672542] Starting Upmpd Daemon
Dec 15 15:24:32 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "my_music"...
Dec 15 15:24:32 volumio volumio[1193]: info: Loading plugin "mpd"...
Dec 15 15:24:33 volumio volumio[1193]: info: Loading plugin "upnp_browser"...
Dec 15 15:24:34 volumio sudo[1247]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:35 volumio volumio[1193]: info: Starting UPNP Browser
Dec 15 15:24:35 volumio volumio[1193]: info: Loading plugin "alarm-clock"...
Dec 15 15:24:36 volumio volumio[1193]: info: Loading plugin "airplay_emulation"...
Dec 15 15:24:36 volumio volumio[1193]: info: Starting Shairport Sync
Dec 15 15:24:36 volumio volumio[1193]: info: Loading plugin "last_100"...
Dec 15 15:24:36 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully.
Dec 15 15:24:36 volumio volumio[1193]: info: Loading plugin "webradio"...
Dec 15 15:24:36 volumio volumio[1193]: info: Loading plugin "i2s_dacs"...
Dec 15 15:24:36 volumio volumio[1193]: info: I2S DAC not set, start Auto-detection
Dec 15 15:24:36 volumio volumio[1193]: info: Loading plugin "volumiodiscovery"...
Dec 15 15:24:36 volumio volumio[1193]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 15 15:24:36 volumio node[1193]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 15 15:24:36 volumio volumio[1193]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 15 15:24:36 volumio node[1193]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 15 15:24:36 volumio volumio[1193]: *** WARNING *** For more information see
Dec 15 15:24:36 volumio node[1193]: *** WARNING *** For more information see
Dec 15 15:24:36 volumio volumio[1193]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 15 15:24:36 volumio node[1193]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 15 15:24:36 volumio volumio[1193]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 15 15:24:36 volumio node[1193]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 15 15:24:36 volumio volumio[1193]: *** WARNING *** For more information see
Dec 15 15:24:36 volumio node[1193]: *** WARNING *** For more information see
Dec 15 15:24:36 volumio volumio[1193]: info: Applying required configuration parameters for plugin volumiodiscovery
Dec 15 15:24:36 volumio volumio[1193]: info: Discovery: Started advertising with name: Volumio
Dec 15 15:24:36 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 15 15:24:36 volumio volumio[1193]: info: Loading plugin "spop"...
Dec 15 15:24:37 volumio systemd[1]: Started rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:24:39 volumio python[1270]: RFID Manager läuft. Web-Interface auf Port 5001.
Dec 15 15:24:39 volumio python[1270]: * Serving Flask app 'app'
Dec 15 15:24:39 volumio python[1270]: * Debug mode: off
Dec 15 15:24:39 volumio python[1270]: Address already in use
Dec 15 15:24:39 volumio python[1270]: Port 5001 is in use by another program. Either identify and stop that program, or start the server with a different port.
Dec 15 15:24:39 volumio systemd[1]: rfid-player.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:24:39 volumio systemd[1]: rfid-player.service: Failed with result 'exit-code'.
Dec 15 15:24:39 volumio systemd[1]: rfid-player.service: Consumed 1.593s CPU time.
Dec 15 15:24:39 volumio systemd[1]: rfid-player.service: Scheduled restart job, restart counter is at 1.
Dec 15 15:24:39 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2.
Dec 15 15:24:39 volumio systemd[1]: Stopped rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:24:39 volumio systemd[1]: rfid-player.service: Consumed 1.593s CPU time.
Dec 15 15:24:39 volumio systemd[1]: Starting rfid-player.service - RFID Card Player for Volumio...
Dec 15 15:24:39 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Dec 15 15:24:39 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Dec 15 15:24:39 volumio upmpdcli[1272]: Could not open config: /tmp/upmpdcli.conf
Dec 15 15:24:39 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:24:39 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Dec 15 15:24:40 volumio volumio[1193]: info: Loading plugin "gpio-buttons"...
Dec 15 15:24:40 volumio volumio[1193]: gpiox_arm32 V2.2.1
Dec 15 15:24:40 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Dec 15 15:24:41 volumio volumio[1193]: info: gpio-buttons - GPIO-Buttons initialized
Dec 15 15:24:41 volumio volumio[1193]: info: Loading plugin "outputs"...
Dec 15 15:24:41 volumio volumio[1193]: info: Loading plugin "albumart"...
Dec 15 15:24:41 volumio volumio[1193]: info: Plugin example_plugin is not enabled
Dec 15 15:24:41 volumio volumio[1193]: info: Loading plugin "inputs"...
Dec 15 15:24:41 volumio volumio[1193]: info: Loading plugin "updater_comm"...
Dec 15 15:24:41 volumio volumio[1193]: info: Plugin mpdemulation is not enabled
Dec 15 15:24:41 volumio volumio[1193]: info: Loading plugin "rest_api"...
Dec 15 15:24:41 volumio volumio[1193]: info: Loading plugin "websocket"...
Dec 15 15:24:41 volumio volumio[1193]: info: Starting Socket.io Server version 1.7.4
Dec 15 15:24:41 volumio volumio[1193]: info: Loading plugin "cdplayer"...
Dec 15 15:24:41 volumio volumio[1193]: info: Applying required configuration parameters for plugin cdplayer
Dec 15 15:24:42 volumio volumio[1193]: info: Loading i18n strings for locale de
Dec 15 15:24:42 volumio systemd[1]: Started volumio-rfid-player.service - Volumio RFID Jukebox Player (Moode Prinzip).
Dec 15 15:24:42 volumio volumio[1193]: Updating browse sources language
Dec 15 15:24:42 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::initPlayerControls
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 15:24:43 volumio volumio[1193]: Express server listening on port 3000
Dec 15 15:24:43 volumio volumio[1193]: [Metrics] WebUI: 16s 904.09ms
Dec 15 15:24:43 volumio volumio[1193]: info: CoreStateMachine::resetVolumioState
Dec 15 15:24:43 volumio volumio[1193]: info: CoreStateMachine::getcurrentVolume
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::volumioRetrievevolume
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 15:24:43 volumio sudo[1313]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 15 15:24:43 volumio sudo[1313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:43 volumio sudo[1311]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 15 15:24:43 volumio sudo[1311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:43 volumio sudo[1313]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:43 volumio sudo[1311]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:43 volumio volumio[1193]: info: Volumio Network Manager: Network status updated: 1
Dec 15 15:24:43 volumio volumio[1276]: Forking 3 albumart workers
Dec 15 15:24:43 volumio volumio[1193]: info: CoreStateMachine::pushState
Dec 15 15:24:43 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState
Dec 15 15:24:43 volumio volumio[1193]: info: CoreStateMachine::updateTrackBlock
Dec 15 15:24:43 volumio volumio[1193]: info: CorePlayQueue::getTrackBlock
Dec 15 15:24:43 volumio volumio[1193]: info: CoreCommandRouter::volumioRetrievevolume
Dec 15 15:24:44 volumio volumio[1193]: verbose: New Socket.io Connection to 192.168.178.106 from 192.168.178.20 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.1 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 1
Dec 15 15:24:44 volumio volumio[1193]: info: Reloading queue from file
Dec 15 15:24:44 volumio volumio[1193]: verbose: New Socket.io Connection to 192.168.178.106 from 192.168.178.20 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.1 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 2
Dec 15 15:24:44 volumio volumio[1193]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Dec 15 15:24:44 volumio volumio[1193]: info: CoreStateMachine::pushState
Dec 15 15:24:44 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:44 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 15:24:44 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState
Dec 15 15:24:44 volumio volumio[1193]: info: CoreStateMachine::setRepeat null single undefined
Dec 15 15:24:44 volumio volumio[1193]: info: CoreStateMachine::pushState
Dec 15 15:24:44 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:44 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState
Dec 15 15:24:44 volumio volumio[1193]: info: CoreStateMachine::setRandom null
Dec 15 15:24:44 volumio volumio[1193]: info: CoreStateMachine::pushState
Dec 15 15:24:44 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:44 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState
Dec 15 15:24:44 volumio volumio[1193]: info: Setting Device type: Raspberry PI
Dec 15 15:24:45 volumio volumio[1193]: info: Discovery: adding b0e0529d-d5e7-4695-8774-82a2ed59a330
Dec 15 15:24:45 volumio volumio[1193]: info: Discovery: Found device Volumio
Dec 15 15:24:45 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState
Dec 15 15:24:45 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:45 volumio sudo[1364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 15 15:24:45 volumio volumio[1193]: info: Completed loading Core Plugins
Dec 15 15:24:46 volumio sudo[1364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:46 volumio volumio[1193]: info: Preparing to generate the ALSA configuration file
Dec 15 15:24:46 volumio volumio-remote-updater[675]: [2025-12-15 15:24:46] [connect] Successful connection
Dec 15 15:24:46 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 15 15:24:46 volumio volumio[1193]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
Dec 15 15:24:46 volumio volumio[1193]: info: Reading ALSA contributions from plugins.
Dec 15 15:24:46 volumio volumio[1193]: info: Discovery: this is already registered, b0e0529d-d5e7-4695-8774-82a2ed59a330
Dec 15 15:24:46 volumio volumio[1193]: info: Discovery: Found device Volumio
Dec 15 15:24:46 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState
Dec 15 15:24:46 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:46 volumio set-bt-output.sh[1366]: Output 1 (alsa) is disabled
Dec 15 15:24:46 volumio set-bt-output.sh[1366]: allowed_formats=""
Dec 15 15:24:46 volumio set-bt-output.sh[1366]: dop="0"
Dec 15 15:24:46 volumio set-bt-output.sh[1366]: Output 2 (multiroom) is disabled
Dec 15 15:24:46 volumio set-bt-output.sh[1366]: Output 3 (Bluetooth Speaker) is enabled
Dec 15 15:24:46 volumio set-bt-output.sh[1366]: allowed_formats=""
Dec 15 15:24:46 volumio set-bt-output.sh[1366]: dop="0"
Dec 15 15:24:46 volumio set-bt-output.sh[1367]: Output 1 (alsa) is disabled
Dec 15 15:24:46 volumio set-bt-output.sh[1367]: allowed_formats=""
Dec 15 15:24:46 volumio set-bt-output.sh[1367]: dop="0"
Dec 15 15:24:46 volumio set-bt-output.sh[1367]: Output 2 (multiroom) is disabled
Dec 15 15:24:46 volumio set-bt-output.sh[1367]: Output 3 (Bluetooth Speaker) is enabled
Dec 15 15:24:46 volumio set-bt-output.sh[1367]: allowed_formats=""
Dec 15 15:24:46 volumio set-bt-output.sh[1367]: dop="0"
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::volumioGetVisibleSources
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState
Dec 15 15:24:47 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState
Dec 15 15:24:47 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Dec 15 15:24:47 volumio volumio[1193]: info: Received Get System Info
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 15 15:24:47 volumio volumio[1193]: info: Discovery: Getting this device information
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState
Dec 15 15:24:47 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState
Dec 15 15:24:47 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:47 volumio volumio[1193]: info: Listing playlists
Dec 15 15:24:47 volumio volumio[1193]: info: VolumeController::SetAlsaVolume0
Dec 15 15:24:47 volumio volumio[1193]: info: CoreStateMachine::pushState
Dec 15 15:24:47 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 15:24:47 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState
Dec 15 15:24:47 volumio volumio-remote-updater[675]: [2025-12-15 15:24:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765808686 101
Dec 15 15:24:47 volumio volumio[1193]: 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: 4
Dec 15 15:24:47 volumio volumio[1193]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0
Dec 15 15:24:49 volumio volumio[1193]: info: Asound.conf file unchanged, so no further update is needed
Dec 15 15:24:49 volumio volumio[1193]: info: Output device has changed, restarting MPD
Dec 15 15:24:49 volumio volumio[1193]: info: Output device has changed, restarting Shairport Sync
Dec 15 15:24:49 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:49 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 15:24:49 volumio sudo[1371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 15 15:24:49 volumio sudo[1371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:49 volumio sudo[1373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 15 15:24:49 volumio sudo[1371]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:49 volumio set-bt-output.sh[1379]: Output 1 (alsa) is disabled
Dec 15 15:24:49 volumio set-bt-output.sh[1379]: allowed_formats=""
Dec 15 15:24:49 volumio set-bt-output.sh[1379]: dop="0"
Dec 15 15:24:49 volumio set-bt-output.sh[1379]: Output 2 (multiroom) is disabled
Dec 15 15:24:49 volumio set-bt-output.sh[1379]: Output 3 (Bluetooth Speaker) is enabled
Dec 15 15:24:49 volumio set-bt-output.sh[1379]: allowed_formats=""
Dec 15 15:24:49 volumio set-bt-output.sh[1379]: dop="0"
Dec 15 15:24:49 volumio set-bt-output.sh[1380]: Output 1 (alsa) is disabled
Dec 15 15:24:49 volumio set-bt-output.sh[1380]: allowed_formats=""
Dec 15 15:24:49 volumio set-bt-output.sh[1380]: dop="0"
Dec 15 15:24:49 volumio set-bt-output.sh[1380]: Output 2 (multiroom) is disabled
Dec 15 15:24:49 volumio set-bt-output.sh[1380]: Output 3 (Bluetooth Speaker) is enabled
Dec 15 15:24:49 volumio set-bt-output.sh[1380]: allowed_formats=""
Dec 15 15:24:49 volumio set-bt-output.sh[1380]: dop="0"
Dec 15 15:24:49 volumio volumio[1193]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 15 15:24:49 volumio volumio[1193]: info: ___________ START PLUGINS ___________
Dec 15 15:24:49 volumio sudo[1373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:49 volumio volumio[1193]: info: ControllerMpd::onStart: Initializing MPD
Dec 15 15:24:49 volumio volumio[1193]: info: Creating MPD Configuration file
Dec 15 15:24:49 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 15:24:49 volumio volumio[1193]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 15 15:24:49 volumio volumio[1193]: info: [1765808689913] CoreMusicLibrary::Adding element Medienserver
Dec 15 15:24:49 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 15:24:49 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Dec 15 15:24:49 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM
Dec 15 15:24:50 volumio volumio[1193]: info: UPNP Browser: Client initialized successfully
Dec 15 15:24:50 volumio sudo[1384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 15 15:24:50 volumio sudo[1384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:50 volumio sudo[1384]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:50 volumio sudo[1387]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 15 15:24:50 volumio sudo[1387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:50 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:50 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 15:24:50 volumio systemd[1]: mpd.service: Failed with result 'signal'.
Dec 15 15:24:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 15 15:24:50 volumio systemd[1]: mpd.service: Consumed 6.854s CPU time.
Dec 15 15:24:50 volumio systemd[1]: mpd.socket: Deactivated successfully.
Dec 15 15:24:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 15 15:24:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 15 15:24:50 volumio volumio[1193]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 15 15:24:50 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:50 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 15:24:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 15 15:24:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 15 15:24:50 volumio sudo[1409]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 15 15:24:50 volumio sudo[1409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 15 15:24:50 volumio sudo[1409]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:51 volumio volumio[1193]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 15 15:24:51 volumio volumio[1193]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 15 15:24:51 volumio volumio[1193]: info: [1765808691033] CoreMusicLibrary::Adding element Last_100
Dec 15 15:24:51 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 15:24:51 volumio volumio[1193]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 15 15:24:51 volumio volumio[1193]: info: [1765808691038] CoreMusicLibrary::Adding element Webradio
Dec 15 15:24:51 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 15:24:51 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 15 15:24:51 volumio volumio[1193]: info: Initializing BBC Radios
Dec 15 15:24:52 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 15 15:24:52 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 15:24:52 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Dec 15 15:24:52 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Dec 15 15:24:52 volumio systemd[1]: setdatetime-helper.service: Consumed 1.169s CPU time.
Dec 15 15:24:52 volumio volumio[1193]: info: Creating Spotify config file
Dec 15 15:24:52 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:24:54 volumio mpd[1419]: 2025-12-15T15:24:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 15 15:24:54 volumio volumio[1319]: Starting albumart workers
Dec 15 15:24:54 volumio systemd[1]: Started rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:24:54 volumio volumio[1321]: Starting albumart workers
Dec 15 15:24:55 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3.
Dec 15 15:24:55 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Dec 15 15:24:55 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Dec 15 15:24:55 volumio volumio[1193]: info: gpio-buttons - Initializing GPIO triggers...
Dec 15 15:24:55 volumio sudo[1364]: pam_unix(sudo:session): session closed for user root
Dec 15 15:24:55 volumio volumio[1193]: info: gpio-buttons - ✅ GPIO13 configured for playPause
Dec 15 15:24:55 volumio volumio[1193]: info: gpio-buttons - ✅ GPIO5 configured for volumeUp
Dec 15 15:24:55 volumio volumio[1193]: info: gpio-buttons - ✅ GPIO6 configured for volumeDown
Dec 15 15:24:55 volumio volumio[1193]: info: gpio-buttons - ✅ GPIO26 configured for previous
Dec 15 15:24:55 volumio volumio[1193]: info: gpio-buttons - ✅ GPIO19 configured for next
Dec 15 15:24:55 volumio volumio[1193]: info: [CDPlayer]: Adding CDPlayer to Browse Sources
Dec 15 15:24:55 volumio volumio[1193]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 15 15:24:55 volumio volumio[1193]: info: [1765808695467] CoreMusicLibrary::Adding element CDPlayer
Dec 15 15:24:55 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 15:24:55 volumio volumio[1193]: Cannot find translation for source CDPlayer
Dec 15 15:24:55 volumio volumio[1193]: info: [CDPlayer]: [tray-watcher] Udevadm monitor started
Dec 15 15:24:55 volumio volumio[1193]: info: Volumio Calling Home
Dec 15 15:24:55 volumio sudo[1477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable --now cdplayer_stream.service
Dec 15 15:24:55 volumio sudo[1477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:24:56 volumio systemd[1]: Reloading.
Dec 15 15:24:56 volumio python[1459]: RFID Manager läuft. Web-Interface auf Port 5001.
Dec 15 15:24:56 volumio python[1459]: * Serving Flask app 'app'
Dec 15 15:24:56 volumio python[1459]: * Debug mode: off
Dec 15 15:24:56 volumio python[1459]: Address already in use
Dec 15 15:24:56 volumio python[1459]: Port 5001 is in use by another program. Either identify and stop that program, or start the server with a different port.
Dec 15 15:24:56 volumio volumio[1316]: Starting albumart workers
Dec 15 15:24:56 volumio volumio[1193]: info: gpio-buttons - GPIO-Buttons started
Dec 15 15:24:57 volumio systemd[1]: rfid-player.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:24:57 volumio systemd[1]: rfid-player.service: Failed with result 'exit-code'.
Dec 15 15:24:57 volumio systemd[1]: rfid-player.service: Consumed 1.530s CPU time.
Dec 15 15:24:58 volumio systemd[1]: rfid-player.service: Scheduled restart job, restart counter is at 2.
Dec 15 15:24:58 volumio systemd[1]: Stopped rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:24:58 volumio systemd[1]: rfid-player.service: Consumed 1.530s CPU time.
Dec 15 15:24:58 volumio systemd[1]: Starting rfid-player.service - RFID Card Player for Volumio...
Dec 15 15:24:59 volumio volumio[1193]: info: MPD Permissions set
Dec 15 15:24:59 volumio volumio[1193]: info: MPD Permissions set
Dec 15 15:24:59 volumio volumio[1193]: info: Upmpdcli Daemon Started
Dec 15 15:24:59 volumio volumio[1193]: info: Volumio called home
Dec 15 15:24:59 volumio volumio[1193]: info: Spotify config file written
Dec 15 15:24:59 volumio sudo[1509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 15 15:24:59 volumio sudo[1509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:25:00 volumio 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.
Dec 15 15:25:00 volumio 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.
Dec 15 15:25:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 15:25:00 volumio go-librespot[1511]: go-librespot daemon starting...
Dec 15 15:25:00 volumio sudo[1509]: pam_unix(sudo:session): session closed for user root
Dec 15 15:25:01 volumio volumio[1193]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 15 15:25:01 volumio volumio[1193]: info: No need to fix Spotify hosts
Dec 15 15:25:02 volumio volumio[1193]: info: New Spotify access tokenBQC9Q08ONy...
Dec 15 15:25:02 volumio volumio[1193]: info: Spotify credentials grant success - running version from March 24, 2019
Dec 15 15:25:02 volumio volumio[1193]: info: Starting Shairport Sync
Dec 15 15:25:02 volumio volumio[1193]: info: Starting Shairport Sync
Dec 15 15:25:02 volumio volumio[1193]: info: Starting Shairport Sync
Dec 15 15:25:02 volumio sudo[1544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 15 15:25:02 volumio sudo[1546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 15 15:25:02 volumio sudo[1544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:25:03 volumio sudo[1546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:25:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 15 15:25:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 15 15:25:03 volumio sudo[1548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 15 15:25:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 15:25:03 volumio sudo[1548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 15:25:03 volumio systemd[1]: shairport-sync.service: Consumed 1.665s CPU time.
Dec 15 15:25:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 15:25:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 15 15:25:03 volumio sudo[1544]: pam_unix(sudo:session): session closed for user root
Dec 15 15:25:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 15 15:25:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 15:25:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 15:25:03 volumio sudo[1548]: pam_unix(sudo:session): session closed for user root
Dec 15 15:25:03 volumio sudo[1546]: pam_unix(sudo:session): session closed for user root
Dec 15 15:25:03 volumio volumio[1193]: info: Shairport-Sync Started
Dec 15 15:25:03 volumio volumio[1193]: Error adding Membership: Error: addMembership EINVAL
Dec 15 15:25:03 volumio volumio[1193]: info: Shairport-Sync Started
Dec 15 15:25:03 volumio volumio[1193]: info: Shairport-Sync Started
Dec 15 15:25:03 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState
Dec 15 15:25:03 volumio volumio[1193]: info: CorePlayQueue::getTrack 0
Dec 15 15:25:04 volumio volumio[1193]: SPOTIFY: User informations: {"country":"DE","display_name":"molexx86_music","email":"dgau@me.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31lcn3ntm5ntm5vu7iniojqpql5m"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31lcn3ntm5ntm5vu7iniojqpql5m","id":"31lcn3ntm5ntm5vu7iniojqpql5m","images":[],"product":"premium","type":"user","uri":"spotify:user:31lcn3ntm5ntm5vu7iniojqpql5m"}
Dec 15 15:25:04 volumio volumio[1193]: info: Spotify Successfully logged in
Dec 15 15:25:04 volumio volumio[1193]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 15 15:25:04 volumio volumio[1193]: info: [1765808704356] CoreMusicLibrary::Adding element Spotify
Dec 15 15:25:04 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 15:25:04 volumio volumio[1193]: Cannot find translation for source CDPlayer
Dec 15 15:25:04 volumio volumio[1193]: Cannot find translation for source Spotify
Dec 15 15:25:05 volumio volumio[1193]: info: go-librespot daemon successfully initialized
Dec 15 15:25:05 volumio go-librespot[1512]: time="2025-12-15T15:25:05+01:00" level=info msg="running go-librespot ab178ffd"
Dec 15 15:25:05 volumio go-librespot[1512]: time="2025-12-15T15:25:05+01:00" level=debug msg="app state loaded"
Dec 15 15:25:05 volumio go-librespot[1512]: time="2025-12-15T15:25:05+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=info msg="zeroconf server listening on port 44683"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=debug msg="obtained new client token: AABoHDeLPCq2AkRod4VsonxJx4eSZfdFaRkK48dg+PwfARmQLMXHd3YxRyMxXHtPrAajy6QTcTcVF53oegr0HkZYW+N10YBmUlEaAYjy4Tsm4btuZmasxe5RFi8UevjD0RwvsXc/CloV/uP/spvUm3f/4uchnqhDZE3abQH1GJjfRTtKa//sSn0mg34qsVodrcbd3aKZFm5on0GRu+Be0mgwLOvRS4IY0jV9oiM9"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=debug msg="completed keyexchange"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=debug msg="completed challenge"
Dec 15 15:25:06 volumio go-librespot[1512]: time="2025-12-15T15:25:06+01:00" level=info msg="authenticated AP" username="31************************5m"
Dec 15 15:25:07 volumio go-librespot[1512]: time="2025-12-15T15:25:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR"
Dec 15 15:25:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:25:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 15:25:08 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket
Dec 15 15:25:08 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 15:25:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Dec 15 15:25:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 15:25:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 15:25:10 volumio go-librespot[1604]: go-librespot daemon starting...
Dec 15 15:25:11 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket
Dec 15 15:25:11 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 15:25:13 volumio systemd[1]: Started rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:25:14 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket
Dec 15 15:25:14 volumio python[1607]: RFID Manager läuft. Web-Interface auf Port 5001.
Dec 15 15:25:14 volumio python[1607]: * Serving Flask app 'app'
Dec 15 15:25:14 volumio python[1607]: * Debug mode: off
Dec 15 15:25:14 volumio python[1607]: Address already in use
Dec 15 15:25:14 volumio python[1607]: Port 5001 is in use by another program. Either identify and stop that program, or start the server with a different port.
Dec 15 15:25:14 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 15:25:14 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM
Dec 15 15:25:15 volumio systemd[1]: rfid-player.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:25:15 volumio systemd[1]: rfid-player.service: Failed with result 'exit-code'.
Dec 15 15:25:15 volumio systemd[1]: rfid-player.service: Consumed 1.516s CPU time.
Dec 15 15:25:15 volumio systemd[1]: mpd.service: Failed with result 'signal'.
Dec 15 15:25:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 15 15:25:15 volumio systemd[1]: mpd.service: Consumed 3.660s CPU time.
Dec 15 15:25:15 volumio systemd[1]: mpd.socket: Deactivated successfully.
Dec 15 15:25:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 15 15:25:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 15 15:25:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 15 15:25:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 15 15:25:15 volumio systemd[1]: rfid-player.service: Scheduled restart job, restart counter is at 3.
Dec 15 15:25:15 volumio systemd[1]: Stopped rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:25:15 volumio systemd[1]: rfid-player.service: Consumed 1.516s CPU time.
Dec 15 15:25:15 volumio systemd[1]: Starting rfid-player.service - RFID Card Player for Volumio...
Dec 15 15:25:15 volumio sudo[1626]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 15 15:25:15 volumio sudo[1626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 15 15:25:15 volumio sudo[1626]: pam_unix(sudo:session): session closed for user root
Dec 15 15:25:15 volumio go-librespot[1605]: time="2025-12-15T15:25:15+01:00" level=info msg="running go-librespot ab178ffd"
Dec 15 15:25:15 volumio go-librespot[1605]: time="2025-12-15T15:25:15+01:00" level=debug msg="app state loaded"
Dec 15 15:25:15 volumio go-librespot[1605]: time="2025-12-15T15:25:15+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=info msg="zeroconf server listening on port 45189"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=debug msg="obtained new client token: AACLTuR1/rS1A8OiNbRVdv+b9yRe8hWV6eKug0ClFelBl9dJEu/OvMxi6N9Kk7wOGA6VEDn0NxSSLyffbnv0/AQOU92kS8DwnbzRDA9RCClkHxidASTiVquDiIMYc4sO6b8ucNq6YpUKySnZt4owp0CQdNDDYQCIQ5gWQVhehODq3FgLwi9Oz2BEFHptAJ6VpHGVaqkhSCa2G2HR8by3egGxQt9CuveMvfoKdw=="
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=debug msg="completed keyexchange"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=debug msg="completed challenge"
Dec 15 15:25:16 volumio go-librespot[1605]: time="2025-12-15T15:25:16+01:00" level=info msg="authenticated AP" username="31************************5m"
Dec 15 15:25:17 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket
Dec 15 15:25:17 volumio go-librespot[1605]: time="2025-12-15T15:25:17+01:00" level=debug msg="new websocket client"
Dec 15 15:25:17 volumio volumio[1193]: info: Connection to go-librespot Websocket established
Dec 15 15:25:18 volumio go-librespot[1605]: time="2025-12-15T15:25:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR"
Dec 15 15:25:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:25:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 15:25:19 volumio volumio[1193]: info: Connection to go-librespot Websocket closed
Dec 15 15:25:19 volumio mpd[1635]: 2025-12-15T15:25:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 15 15:25:21 volumio volumio[1193]: info: Getting Spotify volume
Dec 15 15:25:21 volumio volumio[1193]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 15:25:21 volumio volumio[1193]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 15 15:25:21 volumio volumio[1193]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 15 15:25:21 volumio volumio[1193]: errno: -111,
Dec 15 15:25:21 volumio volumio[1193]: code: 'ECONNREFUSED',
Dec 15 15:25:21 volumio volumio[1193]: syscall: 'connect',
Dec 15 15:25:21 volumio volumio[1193]: address: '127.0.0.1',
Dec 15 15:25:21 volumio volumio[1193]: port: 9879,
Dec 15 15:25:21 volumio volumio[1193]: response: undefined
Dec 15 15:25:21 volumio volumio[1193]: }
Dec 15 15:25:21 volumio volumio[1193]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 15:25:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Dec 15 15:25:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 15:25:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 15:25:22 volumio go-librespot[1652]: go-librespot daemon starting...
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=info msg="running go-librespot ab178ffd"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="app state loaded"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=info msg="zeroconf server listening on port 33349"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="obtained new client token: AAAuFx8FTyBqA0OVMKQDhnLrOP9hg5rUNRWuGYp/60kAEMG5HcImHZuV46sthRXtfF5e6OcgsrRJNQ0x1qX16Q2YDXsLIU7h4Naf6CQ9IUQLuYlBjza1gBpDFU9v3PA8JmbPwYZpXuedwt04S/3xaEp1xReDJ/xE39RQh1gHDYueVLyDMuy0y9NFYaJOAHjWJWDU/0wUmC0tX4o5i9dwmzwI7NhbsChxRebD0C/6"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="completed keyexchange"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=debug msg="completed challenge"
Dec 15 15:25:27 volumio go-librespot[1653]: time="2025-12-15T15:25:27+01:00" level=info msg="authenticated AP" username="31************************5m"
Dec 15 15:25:28 volumio go-librespot[1653]: time="2025-12-15T15:25:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR"
Dec 15 15:25:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:25:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 15:25:30 volumio systemd[1]: Started rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:25:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Dec 15 15:25:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 15 15:25:31 volumio python[1681]: RFID Manager läuft. Web-Interface auf Port 5001.
Dec 15 15:25:31 volumio python[1681]: * Serving Flask app 'app'
Dec 15 15:25:31 volumio python[1681]: * Debug mode: off
Dec 15 15:25:31 volumio python[1681]: Address already in use
Dec 15 15:25:31 volumio python[1681]: Port 5001 is in use by another program. Either identify and stop that program, or start the server with a different port.
Dec 15 15:25:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 15 15:25:31 volumio go-librespot[1682]: go-librespot daemon starting...
Dec 15 15:25:32 volumio systemd[1]: rfid-player.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 15:25:32 volumio systemd[1]: rfid-player.service: Failed with result 'exit-code'.
Dec 15 15:25:32 volumio systemd[1]: rfid-player.service: Consumed 1.509s CPU time.
Dec 15 15:25:32 volumio systemd[1]: rfid-player.service: Scheduled restart job, restart counter is at 4.
Dec 15 15:25:32 volumio systemd[1]: Stopped rfid-player.service - RFID Card Player for Volumio.
Dec 15 15:25:32 volumio systemd[1]: rfid-player.service: Consumed 1.509s CPU time.
Dec 15 15:25:32 volumio systemd[1]: Starting rfid-player.service - RFID Card Player for Volumio...
Dec 15 15:25:34 volumio sudo[1688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 15:24'
Dec 15 15:25:34 volumio sudo[1688]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025"
VOLUMIO_VERSION="4.073"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"