Dec 18 05:49:00 bureau dhcpcd[691]: eth0: soliciting a DHCP lease Dec 18 05:49:00 bureau ntpd[796]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 18 05:49:00 bureau ntpd[796]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 18 05:49:00 bureau ntpd[796]: DNS: dns_check: DNS error: -11, System error Dec 18 05:49:00 bureau ntpd[796]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Dec 18 05:49:00 bureau kernel: usb 1-1-port2: over-current change #114 Dec 18 05:49:00 bureau kernel: usb 1-1-port2: over-current change #115 Dec 18 05:49:00 bureau dhcpcd[646]: eth0: DHCP lease expired Dec 18 05:49:00 bureau sh[636]: eth0: DHCP lease expired Dec 18 05:49:00 bureau kernel: usb 1-1-port2: over-current change #116 Dec 18 05:49:00 bureau dhcpcd[646]: eth0: soliciting a DHCP lease Dec 18 05:49:00 bureau sh[636]: eth0: soliciting a DHCP lease Dec 18 05:49:00 bureau kernel: usb 1-1-port2: over-current change #117 Dec 18 05:49:01 bureau kernel: usb 1-1-port2: over-current change #118 Dec 18 05:49:01 bureau wireless.js[579]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 18 05:49:01 bureau wireless.js[579]: WIRELESS.JS: Wired network status changed to: ---connected--- Dec 18 05:49:01 bureau wireless.js[579]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 18 05:49:01 bureau wireless.js[579]: WIRELESS.JS: Cleaning previous... Dec 18 05:49:01 bureau kernel: usb 1-1-port2: over-current change #119 Dec 18 05:49:01 bureau wireless.js[579]: WIRELESS.JS: No wireless interface, exiting Dec 18 05:49:01 bureau systemd[1]: wireless.service: Killing process 913 (sh) with signal SIGKILL. Dec 18 05:49:01 bureau systemd[1]: wireless.service: Killing process 914 (systemctl) with signal SIGKILL. Dec 18 05:49:01 bureau systemd[1]: wireless.service: Failed with result 'protocol'. Dec 18 05:49:01 bureau systemd[1]: Failed to start wireless.service - Wireless Services. Dec 18 05:49:01 bureau systemd[1]: wireless.service: Consumed 11.493s CPU time. Dec 18 05:49:01 bureau systemd[1]: Started volumio.service - Volumio Backend Module. Dec 18 05:49:01 bureau systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Dec 18 05:49:01 bureau systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Dec 18 05:49:01 bureau systemd[1]: Received SIGRTMIN+21 from PID 279 (plymouthd). Dec 18 05:49:01 bureau systemd[1]: Received SIGRTMIN+21 from PID 279 (plymouthd). Dec 18 05:49:01 bureau systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Dec 18 05:49:01 bureau systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Dec 18 05:49:01 bureau systemd[1]: Started getty@tty1.service - Getty on tty1. Dec 18 05:49:01 bureau systemd[1]: Started serial-getty@ttyAMA0.service - Serial Getty on ttyAMA0. Dec 18 05:49:01 bureau kernel: usb 1-1-port2: over-current change #120 Dec 18 05:49:01 bureau systemd[1]: Reached target getty.target - Login Prompts. Dec 18 05:49:01 bureau volumio-cpu-tweak[918]: Setting RT Priority for mpd Dec 18 05:49:01 bureau volumio-cpu-tweak[934]: pid 35's current scheduling policy: SCHED_OTHER Dec 18 05:49:01 bureau volumio-cpu-tweak[934]: pid 35's current scheduling priority: 0 Dec 18 05:49:01 bureau volumio-cpu-tweak[918]: Setting MPD Affinity Dec 18 05:49:01 bureau volumio-cpu-tweak[935]: pid 3's current affinity mask: f Dec 18 05:49:01 bureau volumio-cpu-tweak[918]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 18 05:49:01 bureau volumio-cpu-tweak[918]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Dec 18 05:49:01 bureau systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Dec 18 05:49:01 bureau kernel: usb 1-1-port2: over-current change #121 Dec 18 05:49:02 bureau kernel: usb 1-1-port2: over-current change #122 Dec 18 05:49:02 bureau kernel: usb 1-1-port2: over-current change #123 Dec 18 05:49:02 bureau kernel: usb 1-1-port2: over-current change #124 Dec 18 05:49:03 bureau kernel: usb 1-1-port2: over-current change #125 Dec 18 05:49:03 bureau kernel: usb 1-1-port2: over-current change #126 Dec 18 05:49:03 bureau kernel: usb 1-1-port2: over-current change #127 Dec 18 05:49:03 bureau kernel: usb 1-1-port2: over-current change #128 Dec 18 05:49:04 bureau kernel: usb 1-1-port2: over-current change #129 Dec 18 05:49:04 bureau kernel: usb 1-1-port2: over-current change #130 Dec 18 05:49:04 bureau kernel: usb 1-1-port2: over-current change #131 Dec 18 05:49:04 bureau kernel: usb 1-1-port2: over-current change #132 Dec 18 05:49:05 bureau kernel: usb 1-1-port2: over-current change #133 Dec 18 05:49:05 bureau kernel: usb 1-1-port2: over-current change #134 Dec 18 05:49:05 bureau kernel: usb 1-1-port2: over-current change #135 Dec 18 05:49:05 bureau bash[772]: setdatetime-helper: all HTTPS Date fallbacks failed Dec 18 05:49:05 bureau systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 18 05:49:05 bureau systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 18 05:49:05 bureau systemd[1]: setdatetime-helper.service: Consumed 2.588s CPU time. Dec 18 05:49:05 bureau kernel: usb 1-1-port2: over-current change #136 Dec 18 05:49:06 bureau kernel: usb 1-1-port2: over-current change #137 Dec 18 05:49:06 bureau kernel: usb 1-1-port2: over-current change #138 Dec 18 05:49:06 bureau volumio-remote-updater[576]: [2025-12-18 05:49:06] [connect] Successful connection Dec 18 05:49:06 bureau kernel: usb 1-1-port2: over-current change #139 Dec 18 05:49:06 bureau kernel: usb 1-1-port2: over-current change #140 Dec 18 05:49:07 bureau kernel: usb 1-1-port2: over-current change #141 Dec 18 05:49:07 bureau kernel: usb 1-1-port2: over-current change #142 Dec 18 05:49:07 bureau volumio[916]: info: ------------------------------------------- Dec 18 05:49:07 bureau volumio[916]: info: ----- Volumio3 ---- Dec 18 05:49:07 bureau volumio[916]: info: ------------------------------------------- Dec 18 05:49:07 bureau volumio[916]: info: ----- System startup ---- Dec 18 05:49:07 bureau volumio[916]: info: ------------------------------------------- Dec 18 05:49:07 bureau kernel: usb 1-1-port2: over-current change #143 Dec 18 05:49:07 bureau kernel: usb 1-1-port2: over-current change #144 Dec 18 05:49:08 bureau kernel: usb 1-1-port2: over-current change #145 Dec 18 05:49:08 bureau kernel: usb 1-1-port2: over-current change #146 Dec 18 05:49:08 bureau kernel: usb 1-1-port2: over-current change #147 Dec 18 05:49:08 bureau kernel: usb 1-1-port2: over-current change #148 Dec 18 05:49:09 bureau kernel: usb 1-1-port2: over-current change #149 Dec 18 05:49:09 bureau kernel: usb 1-1-port2: over-current change #150 Dec 18 05:49:09 bureau systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Dec 18 05:49:09 bureau systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 18 05:49:09 bureau volumio[916]: info: MYVOLUMIO Environment detected Dec 18 05:49:09 bureau kernel: usb 1-1-port2: over-current change #151 Dec 18 05:49:09 bureau systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 18 05:49:09 bureau upmpdcli[967]: Could not open config: /tmp/upmpdcli.conf Dec 18 05:49:09 bureau volumio[916]: info: Plugin folders cleanup Dec 18 05:49:09 bureau kernel: usb 1-1-port2: over-current change #152 Dec 18 05:49:09 bureau volumio[916]: info: Scanning into folder /volumio/app/plugins/ Dec 18 05:49:09 bureau systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:09 bureau volumio[916]: info: Scanning category audio_interface Dec 18 05:49:09 bureau systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 18 05:49:09 bureau volumio[916]: info: Scanning category miscellanea Dec 18 05:49:09 bureau volumio[916]: info: Scanning category music_service Dec 18 05:49:09 bureau volumio[916]: info: Scanning category plugins.json Dec 18 05:49:09 bureau volumio[916]: info: Scanning category system_controller Dec 18 05:49:09 bureau volumio[916]: info: Scanning category user_interface Dec 18 05:49:09 bureau volumio[916]: info: Scanning into folder /data/plugins/ Dec 18 05:49:09 bureau volumio[916]: info: Scanning category music_service Dec 18 05:49:09 bureau volumio[916]: info: Plugin folders cleanup completed Dec 18 05:49:09 bureau volumio[916]: info: ------------------------------------------- Dec 18 05:49:09 bureau volumio[916]: info: ----- Core plugins startup ---- Dec 18 05:49:09 bureau volumio[916]: info: ------------------------------------------- Dec 18 05:49:09 bureau volumio[916]: info: Loading plugins from folder /volumio/app/plugins/ Dec 18 05:49:10 bureau volumio[916]: info: Adding plugin upnp to MyMusic Plugins Dec 18 05:49:10 bureau volumio[916]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 18 05:49:10 bureau volumio[916]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 18 05:49:10 bureau volumio[916]: info: Loading plugins from folder /data/plugins/ Dec 18 05:49:10 bureau volumio[916]: info: Loading plugin "system"... Dec 18 05:49:10 bureau volumio[916]: info: Loading plugin "appearance"... Dec 18 05:49:10 bureau kernel: usb 1-1-port2: over-current change #153 Dec 18 05:49:10 bureau kernel: usb 1-1-port2: over-current change #154 Dec 18 05:49:10 bureau kernel: usb 1-1-port2: over-current change #155 Dec 18 05:49:10 bureau kernel: usb 1-1-port2: over-current change #156 Dec 18 05:49:11 bureau kernel: usb 1-1-port2: over-current change #157 Dec 18 05:49:11 bureau kernel: usb 1-1-port2: over-current change #158 Dec 18 05:49:11 bureau kernel: usb 1-1-port2: over-current change #159 Dec 18 05:49:12 bureau kernel: usb 1-1-port2: over-current change #160 Dec 18 05:49:12 bureau kernel: usb 1-1-port2: over-current change #161 Dec 18 05:49:12 bureau kernel: usb 1-1-port2: over-current change #162 Dec 18 05:49:12 bureau kernel: usb 1-1-port2: over-current change #163 Dec 18 05:49:13 bureau kernel: usb 1-1-port2: over-current change #164 Dec 18 05:49:13 bureau kernel: usb 1-1-port2: over-current change #165 Dec 18 05:49:13 bureau kernel: usb 1-1-port2: over-current change #166 Dec 18 05:49:13 bureau volumio[916]: info: Loading plugin "network"... Dec 18 05:49:13 bureau volumio[916]: info: Refreshing Cached IP Addresses Dec 18 05:49:13 bureau volumio[916]: info: Loading plugin "services"... Dec 18 05:49:13 bureau volumio[916]: info: Loading plugin "alsa_controller"... Dec 18 05:49:13 bureau kernel: usb 1-1-port2: over-current change #167 Dec 18 05:49:14 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 18 05:49:14 bureau sudo[974]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 18 05:49:14 bureau sudo[972]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 18 05:49:14 bureau sudo[981]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 18 05:49:14 bureau volumio[916]: info: Loading plugin "wizard"... Dec 18 05:49:14 bureau sudo[974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:14 bureau sudo[972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:14 bureau sudo[981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:14 bureau sudo[972]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:14 bureau kernel: usb 1-1-port2: over-current change #168 Dec 18 05:49:14 bureau sudo[981]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:14 bureau volumio[916]: info: Loading plugin "networkfs"... Dec 18 05:49:14 bureau sudo[974]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:14 bureau volumio[916]: info: Starting Udev Watcher for removable devices Dec 18 05:49:14 bureau volumio[916]: info: Ignoring mount for partition: boot Dec 18 05:49:14 bureau volumio[916]: info: Ignoring mount for partition: volumio Dec 18 05:49:14 bureau volumio[916]: info: Ignoring mount for partition: volumio_data Dec 18 05:49:14 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 18 05:49:14 bureau volumio[916]: info: Loading plugin "volumio_command_line_client"... Dec 18 05:49:14 bureau volumio[916]: info: Loading plugin "upnp"... Dec 18 05:49:14 bureau volumio[916]: info: [1766033354301] Starting Upmpd Daemon Dec 18 05:49:14 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 18 05:49:14 bureau volumio[916]: info: Loading plugin "my_music"... Dec 18 05:49:14 bureau kernel: usb 1-1-port2: over-current change #169 Dec 18 05:49:14 bureau volumio[916]: info: Loading plugin "mpd"... Dec 18 05:49:14 bureau kernel: usb 1-1-port2: over-current change #170 Dec 18 05:49:14 bureau kernel: usb 1-1-port2: over-current change #171 Dec 18 05:49:15 bureau kernel: usb 1-1-port2: over-current change #172 Dec 18 05:49:15 bureau volumio[916]: info: Loading plugin "upnp_browser"... Dec 18 05:49:15 bureau kernel: usb 1-1-port2: over-current change #173 Dec 18 05:49:15 bureau kernel: usb 1-1-port2: over-current change #174 Dec 18 05:49:15 bureau kernel: usb 1-1-port2: over-current change #175 Dec 18 05:49:16 bureau kernel: usb 1-1-port2: over-current change #176 Dec 18 05:49:16 bureau kernel: usb 1-1-port2: over-current change #177 Dec 18 05:49:16 bureau kernel: usb 1-1-port2: over-current change #178 Dec 18 05:49:16 bureau kernel: usb 1-1-port2: over-current change #179 Dec 18 05:49:17 bureau kernel: usb 1-1-port2: over-current change #180 Dec 18 05:49:17 bureau kernel: usb 1-1-port2: over-current change #181 Dec 18 05:49:17 bureau kernel: usb 1-1-port2: over-current change #182 Dec 18 05:49:17 bureau kernel: usb 1-1-port2: over-current change #183 Dec 18 05:49:18 bureau kernel: usb 1-1-port2: over-current change #184 Dec 18 05:49:18 bureau volumio[916]: info: Starting UPNP Browser Dec 18 05:49:18 bureau volumio[916]: info: Loading plugin "alarm-clock"... Dec 18 05:49:18 bureau kernel: usb 1-1-port2: over-current change #185 Dec 18 05:49:18 bureau kernel: usb 1-1-port2: over-current change #186 Dec 18 05:49:18 bureau volumio[916]: info: Loading plugin "airplay_emulation"... Dec 18 05:49:18 bureau volumio[916]: info: Starting Shairport Sync Dec 18 05:49:18 bureau volumio[916]: info: Loading plugin "last_100"... Dec 18 05:49:18 bureau volumio[916]: info: Loading plugin "webradio"... Dec 18 05:49:18 bureau kernel: usb 1-1-port2: over-current change #187 Dec 18 05:49:19 bureau volumio[916]: info: Loading plugin "i2s_dacs"... Dec 18 05:49:19 bureau kernel: usb 1-1-port2: over-current change #188 Dec 18 05:49:19 bureau volumio[916]: info: Loading plugin "volumiodiscovery"... Dec 18 05:49:19 bureau volumio[916]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 18 05:49:19 bureau volumio[916]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 18 05:49:19 bureau volumio[916]: *** WARNING *** For more information see Dec 18 05:49:19 bureau volumio[916]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 18 05:49:19 bureau volumio[916]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 18 05:49:19 bureau volumio[916]: *** WARNING *** For more information see Dec 18 05:49:19 bureau node[916]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 18 05:49:19 bureau node[916]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 18 05:49:19 bureau node[916]: *** WARNING *** For more information see Dec 18 05:49:19 bureau node[916]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 18 05:49:19 bureau node[916]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 18 05:49:19 bureau node[916]: *** WARNING *** For more information see Dec 18 05:49:19 bureau volumio[916]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 18 05:49:19 bureau volumio[916]: info: Discovery: Started advertising with name: Bureau Dec 18 05:49:19 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 18 05:49:19 bureau volumio[916]: info: Loading plugin "spop"... Dec 18 05:49:19 bureau kernel: usb 1-1-port2: over-current change #189 Dec 18 05:49:19 bureau systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 18 05:49:19 bureau kernel: usb 1-1-port2: over-current change #190 Dec 18 05:49:19 bureau kernel: usb 1-1-port2: over-current change #191 Dec 18 05:49:20 bureau kernel: usb 1-1-port2: over-current change #192 Dec 18 05:49:20 bureau kernel: usb 1-1-port2: over-current change #193 Dec 18 05:49:20 bureau kernel: usb 1-1-port2: over-current change #194 Dec 18 05:49:20 bureau kernel: usb 1-1-port2: over-current change #195 Dec 18 05:49:21 bureau kernel: usb 1-1-port2: over-current change #196 Dec 18 05:49:21 bureau kernel: usb 1-1-port2: over-current change #197 Dec 18 05:49:21 bureau volumio-remote-updater[576]: [2025-12-18 05:49:21] [connect] Successful connection Dec 18 05:49:21 bureau kernel: usb 1-1-port2: over-current change #198 Dec 18 05:49:22 bureau kernel: usb 1-1-port2: over-current change #199 Dec 18 05:49:22 bureau kernel: usb 1-1-port2: over-current change #200 Dec 18 05:49:22 bureau kernel: usb 1-1-port2: over-current change #201 Dec 18 05:49:22 bureau volumio[916]: info: Loading plugin "outputs"... Dec 18 05:49:22 bureau volumio[916]: info: Loading plugin "albumart"... Dec 18 05:49:22 bureau volumio[916]: info: Plugin example_plugin is not enabled Dec 18 05:49:22 bureau volumio[916]: info: Loading plugin "inputs"... Dec 18 05:49:22 bureau volumio[916]: info: Loading plugin "updater_comm"... Dec 18 05:49:22 bureau kernel: usb 1-1-port2: over-current change #202 Dec 18 05:49:22 bureau volumio[916]: info: Plugin mpdemulation is not enabled Dec 18 05:49:22 bureau volumio[916]: info: Loading plugin "rest_api"... Dec 18 05:49:23 bureau volumio[916]: info: Loading plugin "websocket"... Dec 18 05:49:23 bureau volumio[916]: info: Starting Socket.io Server version 1.7.4 Dec 18 05:49:23 bureau volumio[916]: info: Loading plugin "podcast"... Dec 18 05:49:23 bureau kernel: usb 1-1-port2: over-current change #203 Dec 18 05:49:23 bureau kernel: usb 1-1-port2: over-current change #204 Dec 18 05:49:23 bureau kernel: usb 1-1-port2: over-current change #205 Dec 18 05:49:23 bureau kernel: usb 1-1-port2: over-current change #206 Dec 18 05:49:24 bureau kernel: usb 1-1-port2: over-current change #207 Dec 18 05:49:24 bureau dhcpcd[646]: timed out Dec 18 05:49:24 bureau sh[636]: timed out Dec 18 05:49:24 bureau dhcpcd[646]: dhcpcd exited Dec 18 05:49:24 bureau sh[593]: ifup: failed to bring up eth0 Dec 18 05:49:24 bureau systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:24 bureau kernel: usb 1-1-port2: over-current change #208 Dec 18 05:49:24 bureau systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 18 05:49:24 bureau volumio[916]: info: ControllerPodcast::constructor Dec 18 05:49:24 bureau ifplugd(eth0)[816]: client: command failed: No such device (-19) Dec 18 05:49:24 bureau ifplugd(eth0)[816]: client: sending commands to dhcpcd process Dec 18 05:49:24 bureau dhcpcd[691]: control command: dhcpcd eth0 Dec 18 05:49:24 bureau dhcpcd[691]: control_free: No such file or directory Dec 18 05:49:24 bureau kernel: usb 1-1-port2: over-current change #209 Dec 18 05:49:24 bureau volumio[1008]: Forking 3 albumart workers Dec 18 05:49:24 bureau kernel: usb 1-1-port2: over-current change #210 Dec 18 05:49:25 bureau ifplugd(eth0)[816]: Program executed successfully. Dec 18 05:49:25 bureau ifplugd[747]: Network Interface Plugging Daemon...start eth0...done. Dec 18 05:49:25 bureau systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Dec 18 05:49:25 bureau systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 18 05:49:25 bureau systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 18 05:49:25 bureau systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 18 05:49:25 bureau kernel: usb 1-1-port2: over-current change #211 Dec 18 05:49:25 bureau systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 18 05:49:25 bureau upmpdcli[1110]: Could not open config: /tmp/upmpdcli.conf Dec 18 05:49:25 bureau systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:25 bureau systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 18 05:49:25 bureau kernel: usb 1-1-port2: over-current change #212 Dec 18 05:49:25 bureau kernel: usb 1-1-port2: over-current change #213 Dec 18 05:49:25 bureau kernel: usb 1-1-port2: over-current change #214 Dec 18 05:49:26 bureau volumio[916]: info: Loading i18n strings for locale fr Dec 18 05:49:26 bureau kernel: usb 1-1-port2: over-current change #215 Dec 18 05:49:26 bureau volumio[916]: Updating browse sources language Dec 18 05:49:26 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 05:49:26 bureau kernel: usb 1-1-port2: over-current change #216 Dec 18 05:49:26 bureau kernel: usb 1-1-port2: over-current change #217 Dec 18 05:49:26 bureau kernel: usb 1-1-port2: over-current change #218 Dec 18 05:49:27 bureau kernel: usb 1-1-port2: over-current change #219 Dec 18 05:49:27 bureau kernel: usb 1-1-port2: over-current change #220 Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::initPlayerControls Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 05:49:27 bureau volumio[916]: Express server listening on port 3000 Dec 18 05:49:27 bureau volumio[916]: [Metrics] WebUI: 21s 762.73ms Dec 18 05:49:27 bureau kernel: usb 1-1-port2: over-current change #221 Dec 18 05:49:27 bureau volumio[916]: info: CoreStateMachine::resetVolumioState Dec 18 05:49:27 bureau volumio[916]: info: CoreStateMachine::getcurrentVolume Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::volumioRetrievevolume Dec 18 05:49:27 bureau volumio[916]: info: CoreStateMachine::pushState Dec 18 05:49:27 bureau volumio[916]: info: CorePlayQueue::getTrack 0 Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 05:49:27 bureau volumio[916]: info: CoreCommandRouter::volumioPushState Dec 18 05:49:27 bureau kernel: usb 1-1-port2: over-current change #222 Dec 18 05:49:28 bureau sudo[1145]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 18 05:49:28 bureau sudo[1147]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 18 05:49:28 bureau kernel: usb 1-1-port2: over-current change #223 Dec 18 05:49:28 bureau sudo[1145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:28 bureau sudo[1145]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:28 bureau sudo[1147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:28 bureau sudo[1147]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:28 bureau volumio[916]: info: Volumio Network Manager: Network status updated: 0 Dec 18 05:49:28 bureau kernel: usb 1-1-port2: over-current change #224 Dec 18 05:49:28 bureau volumio[916]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Dec 18 05:49:28 bureau volumio[916]: wlan0 Interface doesn't support scanning. Dec 18 05:49:28 bureau volumio[916]: info: Cannot use regular scanning, forcing with ap-force Dec 18 05:49:28 bureau kernel: usb 1-1-port2: over-current change #225 Dec 18 05:49:28 bureau sudo[1160]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Dec 18 05:49:28 bureau sudo[1160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:28 bureau kernel: usb 1-1-port2: over-current change #226 Dec 18 05:49:29 bureau sudo[1160]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:29 bureau volumio[916]: command failed: No such device (-19) Dec 18 05:49:29 bureau volumio[916]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Dec 18 05:49:29 bureau volumio[916]: command failed: No such device (-19) Dec 18 05:49:29 bureau kernel: usb 1-1-port2: over-current change #227 Dec 18 05:49:29 bureau kernel: usb 1-1-port2: over-current change #228 Dec 18 05:49:29 bureau kernel: usb 1-1-port2: over-current change #229 Dec 18 05:49:29 bureau kernel: usb 1-1-port2: over-current change #230 Dec 18 05:49:30 bureau kernel: usb 1-1-port2: over-current change #231 Dec 18 05:49:30 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:49:30 bureau volumio[916]: info: Reloading queue from file Dec 18 05:49:30 bureau volumio[916]: info: CoreStateMachine::setRepeat null single undefined Dec 18 05:49:30 bureau volumio[916]: info: CoreStateMachine::pushState Dec 18 05:49:30 bureau volumio[916]: info: CorePlayQueue::getTrack 0 Dec 18 05:49:30 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 05:49:30 bureau volumio[916]: info: CoreCommandRouter::volumioPushState Dec 18 05:49:30 bureau volumio[916]: info: CoreStateMachine::setRandom null Dec 18 05:49:30 bureau volumio[916]: info: CoreStateMachine::pushState Dec 18 05:49:30 bureau volumio[916]: info: CorePlayQueue::getTrack 0 Dec 18 05:49:30 bureau volumio[916]: info: CoreCommandRouter::volumioPushState Dec 18 05:49:30 bureau kernel: usb 1-1-port2: over-current change #232 Dec 18 05:49:30 bureau volumio[916]: info: Setting Device type: Raspberry PI Dec 18 05:49:30 bureau volumio[916]: info: Completed loading Core Plugins Dec 18 05:49:30 bureau volumio[916]: info: Preparing to generate the ALSA configuration file Dec 18 05:49:30 bureau kernel: usb 1-1-port2: over-current change #233 Dec 18 05:49:31 bureau kernel: usb 1-1-port2: over-current change #234 Dec 18 05:49:31 bureau volumio[916]: info: Discovery: adding 305f60fc-996a-4a9c-a11d-4b5e2f41942d Dec 18 05:49:31 bureau volumio[916]: info: Discovery: Found device Bureau Dec 18 05:49:31 bureau volumio[916]: info: CoreCommandRouter::volumioGetState Dec 18 05:49:31 bureau volumio[916]: info: CorePlayQueue::getTrack 0 Dec 18 05:49:31 bureau volumio[916]: info: Asound.conf file unchanged, so no further update is needed Dec 18 05:49:31 bureau volumio[916]: info: Output device has changed, restarting MPD Dec 18 05:49:31 bureau sudo[1184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 18 05:49:31 bureau sudo[1184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:31 bureau kernel: usb 1-1-port2: over-current change #235 Dec 18 05:49:31 bureau volumio[916]: info: Output device has changed, restarting Shairport Sync Dec 18 05:49:31 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:31 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:49:31 bureau sudo[1187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 18 05:49:31 bureau sudo[1187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:31 bureau kernel: usb 1-1-port2: over-current change #236 Dec 18 05:49:31 bureau sudo[1187]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:31 bureau volumio[916]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 18 05:49:31 bureau sudo[1189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 18 05:49:31 bureau volumio[916]: info: ___________ START PLUGINS ___________ Dec 18 05:49:31 bureau sudo[1189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:31 bureau volumio[916]: info: ControllerMpd::onStart: Initializing MPD Dec 18 05:49:31 bureau volumio[916]: info: Creating MPD Configuration file Dec 18 05:49:31 bureau kernel: usb 1-1-port2: over-current change #237 Dec 18 05:49:31 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 05:49:31 bureau volumio[916]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 18 05:49:31 bureau volumio[916]: info: [1766033371881] CoreMusicLibrary::Adding element Serveurs Média Dec 18 05:49:31 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 05:49:31 bureau systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 18 05:49:31 bureau bash[1112]: setdatetime-helper: all HTTPS Date fallbacks failed Dec 18 05:49:31 bureau sudo[1199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 18 05:49:31 bureau systemd[1]: Starting mpd.service - Music Player Daemon... Dec 18 05:49:31 bureau systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 18 05:49:31 bureau systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 18 05:49:31 bureau systemd[1]: setdatetime-helper.service: Consumed 1.568s CPU time. Dec 18 05:49:31 bureau sudo[1199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:32 bureau volumio[916]: info: UPNP Browser: Client initialized successfully Dec 18 05:49:32 bureau kernel: usb 1-1-port2: over-current change #238 Dec 18 05:49:32 bureau sudo[1197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 18 05:49:32 bureau sudo[1197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:32 bureau systemd[1]: mpd.service: Deactivated successfully. Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:49:32 bureau systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 18 05:49:32 bureau systemd[1]: mpd.socket: Deactivated successfully. Dec 18 05:49:32 bureau systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 18 05:49:32 bureau systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 18 05:49:32 bureau systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 18 05:49:32 bureau sudo[1197]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:32 bureau systemd[1]: Starting mpd.service - Music Player Daemon... Dec 18 05:49:32 bureau kernel: usb 1-1-port2: over-current change #239 Dec 18 05:49:32 bureau volumio[916]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:49:32 bureau kernel: usb 1-1-port2: over-current change #240 Dec 18 05:49:32 bureau sudo[1210]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 18 05:49:32 bureau sudo[1210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 18 05:49:32 bureau volumio[916]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 18 05:49:32 bureau sudo[1215]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 18 05:49:32 bureau sudo[1210]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 18 05:49:32 bureau volumio[916]: info: [1766033372741] CoreMusicLibrary::Adding element Last_100 Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 18 05:49:32 bureau volumio[916]: info: [1766033372800] CoreMusicLibrary::Adding element Webradio Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 05:49:32 bureau kernel: usb 1-1-port2: over-current change #241 Dec 18 05:49:32 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 18 05:49:32 bureau volumio[916]: info: Initializing BBC Radios Dec 18 05:49:33 bureau kernel: usb 1-1-port2: over-current change #242 Dec 18 05:49:33 bureau kernel: usb 1-1-port2: over-current change #243 Dec 18 05:49:33 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 18 05:49:33 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:49:33 bureau volumio[916]: info: Creating Spotify config file Dec 18 05:49:33 bureau kernel: usb 1-1-port2: over-current change #244 Dec 18 05:49:33 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:33 bureau kernel: usb 1-1-port2: over-current change #245 Dec 18 05:49:34 bureau kernel: usb 1-1-port2: over-current change #246 Dec 18 05:49:34 bureau kernel: usb 1-1-port2: over-current change #247 Dec 18 05:49:34 bureau kernel: usb 1-1-port2: over-current change #248 Dec 18 05:49:34 bureau kernel: usb 1-1-port2: over-current change #249 Dec 18 05:49:35 bureau kernel: usb 1-1-port2: over-current change #250 Dec 18 05:49:35 bureau kernel: usb 1-1-port2: over-current change #251 Dec 18 05:49:35 bureau kernel: usb 1-1-port2: over-current change #252 Dec 18 05:49:35 bureau kernel: usb 1-1-port2: over-current change #253 Dec 18 05:49:36 bureau kernel: usb 1-1-port2: over-current change #254 Dec 18 05:49:36 bureau volumio[1078]: Starting albumart workers Dec 18 05:49:36 bureau kernel: usb 1-1-port2: over-current change #255 Dec 18 05:49:36 bureau volumio-remote-updater[576]: [2025-12-18 05:49:36] [connect] Successful connection Dec 18 05:49:36 bureau kernel: usb 1-1-port2: over-current change #256 Dec 18 05:49:36 bureau kernel: usb 1-1-port2: over-current change #257 Dec 18 05:49:37 bureau kernel: usb 1-1-port2: over-current change #258 Dec 18 05:49:37 bureau kernel: usb 1-1-port2: over-current change #259 Dec 18 05:49:37 bureau kernel: usb 1-1-port2: over-current change #260 Dec 18 05:49:37 bureau volumio[1080]: Starting albumart workers Dec 18 05:49:37 bureau volumio[916]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 18 05:49:37 bureau volumio[916]: info: [1766033377904] CoreMusicLibrary::Adding element Podcast Dec 18 05:49:37 bureau kernel: usb 1-1-port2: over-current change #261 Dec 18 05:49:37 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 05:49:37 bureau volumio[916]: Cannot find translation for source Podcast Dec 18 05:49:37 bureau volumio[916]: info: Volumio Calling Home Dec 18 05:49:38 bureau kernel: usb 1-1-port2: over-current change #262 Dec 18 05:49:38 bureau kernel: usb 1-1-port2: over-current change #263 Dec 18 05:49:38 bureau volumio[1075]: Starting albumart workers Dec 18 05:49:38 bureau kernel: usb 1-1-port2: over-current change #264 Dec 18 05:49:38 bureau kernel: usb 1-1-port2: over-current change #265 Dec 18 05:49:39 bureau kernel: usb 1-1-port2: over-current change #266 Dec 18 05:49:39 bureau kernel: usb 1-1-port2: over-current change #267 Dec 18 05:49:39 bureau kernel: usb 1-1-port2: over-current change #268 Dec 18 05:49:40 bureau kernel: usb 1-1-port2: over-current change #269 Dec 18 05:49:40 bureau kernel: usb 1-1-port2: over-current change #270 Dec 18 05:49:40 bureau systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 18 05:49:40 bureau systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 18 05:49:40 bureau systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 18 05:49:40 bureau kernel: usb 1-1-port2: over-current change #271 Dec 18 05:49:40 bureau sudo[1184]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:40 bureau kernel: usb 1-1-port2: over-current change #272 Dec 18 05:49:41 bureau kernel: usb 1-1-port2: over-current change #273 Dec 18 05:49:41 bureau kernel: usb 1-1-port2: over-current change #274 Dec 18 05:49:41 bureau volumio[916]: Unhandled rejection Error: No sockets available, cannot start. Dec 18 05:49:41 bureau volumio[916]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Dec 18 05:49:41 bureau volumio[916]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Dec 18 05:49:41 bureau volumio[916]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Dec 18 05:49:41 bureau volumio[916]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Dec 18 05:49:41 bureau volumio[916]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Dec 18 05:49:41 bureau volumio[916]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Dec 18 05:49:41 bureau volumio[916]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Dec 18 05:49:41 bureau volumio[916]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Dec 18 05:49:41 bureau volumio[916]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:156:14) Dec 18 05:49:41 bureau volumio[916]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Dec 18 05:49:41 bureau volumio[916]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Dec 18 05:49:41 bureau volumio[916]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Dec 18 05:49:41 bureau volumio[916]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Dec 18 05:49:41 bureau volumio[916]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Dec 18 05:49:41 bureau volumio[916]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Dec 18 05:49:41 bureau volumio[916]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 18 05:49:41 bureau volumio[916]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Dec 18 05:49:41 bureau kernel: usb 1-1-port2: over-current change #275 Dec 18 05:49:41 bureau kernel: usb 1-1-port2: over-current change #276 Dec 18 05:49:41 bureau volumio[916]: info: MPD Permissions set Dec 18 05:49:41 bureau volumio[916]: info: MPD Permissions set Dec 18 05:49:41 bureau volumio[916]: info: Upmpdcli Daemon Started Dec 18 05:49:42 bureau kernel: usb 1-1-port2: over-current change #277 Dec 18 05:49:42 bureau kernel: usb 1-1-port2: over-current change #278 Dec 18 05:49:42 bureau volumio[916]: info: Spotify config file written Dec 18 05:49:42 bureau kernel: usb 1-1-port2: over-current change #279 Dec 18 05:49:42 bureau sudo[1260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 18 05:49:42 bureau sudo[1260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:42 bureau kernel: usb 1-1-port2: over-current change #280 Dec 18 05:49:42 bureau 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 18 05:49:42 bureau 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 18 05:49:42 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:42 bureau go-librespot[1262]: go-librespot daemon starting... Dec 18 05:49:43 bureau sudo[1260]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:43 bureau kernel: usb 1-1-port2: over-current change #281 Dec 18 05:49:43 bureau kernel: usb 1-1-port2: over-current change #282 Dec 18 05:49:43 bureau volumio[916]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau kernel: usb 1-1-port2: over-current change #283 Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:49:43 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:49:43 bureau kernel: usb 1-1-port2: over-current change #284 Dec 18 05:49:43 bureau volumio[916]: info: No need to fix Spotify hosts Dec 18 05:49:44 bureau kernel: usb 1-1-port2: over-current change #285 Dec 18 05:49:44 bureau go-librespot[1263]: time="2025-12-18T05:49:44+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:49:44 bureau go-librespot[1263]: time="2025-12-18T05:49:44+01:00" level=debug msg="app state loaded" Dec 18 05:49:44 bureau go-librespot[1263]: time="2025-12-18T05:49:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:49:44 bureau go-librespot[1263]: time="2025-12-18T05:49: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" Dec 18 05:49:44 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:44 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:49:44 bureau volumio[916]: info: Starting Shairport Sync Dec 18 05:49:44 bureau kernel: usb 1-1-port2: over-current change #286 Dec 18 05:49:44 bureau volumio[916]: info: Starting Shairport Sync Dec 18 05:49:44 bureau volumio[916]: info: Starting Shairport Sync Dec 18 05:49:44 bureau kernel: usb 1-1-port2: over-current change #287 Dec 18 05:49:44 bureau sudo[1299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 18 05:49:44 bureau sudo[1299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:44 bureau sudo[1290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 18 05:49:44 bureau sudo[1290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:44 bureau kernel: usb 1-1-port2: over-current change #288 Dec 18 05:49:44 bureau sudo[1304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 18 05:49:44 bureau sudo[1304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:45 bureau systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 18 05:49:45 bureau systemd[1]: shairport-sync.service: Deactivated successfully. Dec 18 05:49:45 bureau kernel: usb 1-1-port2: over-current change #289 Dec 18 05:49:45 bureau systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 18 05:49:45 bureau systemd[1]: shairport-sync.service: Consumed 2.733s CPU time. Dec 18 05:49:45 bureau systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 18 05:49:45 bureau sudo[1299]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:45 bureau sudo[1290]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:45 bureau sudo[1304]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:45 bureau kernel: usb 1-1-port2: over-current change #290 Dec 18 05:49:45 bureau mpd[1216]: 2025-12-18T05:49:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 18 05:49:45 bureau systemd[1]: Started mpd.service - Music Player Daemon. Dec 18 05:49:45 bureau sudo[1199]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:45 bureau sudo[1189]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:45 bureau kernel: usb 1-1-port2: over-current change #291 Dec 18 05:49:45 bureau kernel: usb 1-1-port2: over-current change #292 Dec 18 05:49:45 bureau volumio[916]: info: Completed starting Core Plugins Dec 18 05:49:46 bureau volumio[916]: info: ------------------------------------------- Dec 18 05:49:46 bureau volumio[916]: info: ----- MyVolumio plugins startup ---- Dec 18 05:49:46 bureau volumio[916]: info: ------------------------------------------- Dec 18 05:49:46 bureau volumio[916]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 18 05:49:46 bureau volumio[916]: info: Shairport-Sync Started Dec 18 05:49:46 bureau volumio[916]: Error adding Membership: Error: addMembership EINVAL Dec 18 05:49:46 bureau volumio[916]: info: Shairport-Sync Started Dec 18 05:49:46 bureau kernel: usb 1-1-port2: over-current change #293 Dec 18 05:49:46 bureau volumio[916]: info: Shairport-Sync Started Dec 18 05:49:46 bureau volumio[916]: info: MPD running with PID1216 Dec 18 05:49:46 bureau volumio[916]: ,establishing connection Dec 18 05:49:46 bureau kernel: usb 1-1-port2: over-current change #294 Dec 18 05:49:46 bureau volumio[916]: error: MPD error: The expression evaluated to a falsy value: Dec 18 05:49:46 bureau volumio[916]: assert.ok(self.idling) Dec 18 05:49:46 bureau volumio[916]: error: The expression evaluated to a falsy value: Dec 18 05:49:46 bureau volumio[916]: assert.ok(self.idling) Dec 18 05:49:46 bureau volumio[916]: error: MPD error: The expression evaluated to a falsy value: Dec 18 05:49:46 bureau volumio[916]: assert.ok(self.idling) Dec 18 05:49:46 bureau volumio[916]: error: The expression evaluated to a falsy value: Dec 18 05:49:46 bureau volumio[916]: assert.ok(self.idling) Dec 18 05:49:46 bureau volumio[916]: info: CoreCommandRouter::volumioGetState Dec 18 05:49:46 bureau volumio[916]: info: CorePlayQueue::getTrack 0 Dec 18 05:49:46 bureau kernel: usb 1-1-port2: over-current change #295 Dec 18 05:49:46 bureau volumio[916]: error: updateQueue error: null Dec 18 05:49:46 bureau kernel: usb 1-1-port2: over-current change #296 Dec 18 05:49:47 bureau volumio[916]: info: go-librespot daemon successfully initialized Dec 18 05:49:47 bureau kernel: usb 1-1-port2: over-current change #297 Dec 18 05:49:47 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 18 05:49:47 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:47 bureau kernel: usb 1-1-port2: over-current change #298 Dec 18 05:49:47 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:47 bureau go-librespot[1339]: go-librespot daemon starting... Dec 18 05:49:47 bureau go-librespot[1340]: time="2025-12-18T05:49:47+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:49:47 bureau go-librespot[1340]: time="2025-12-18T05:49:47+01:00" level=debug msg="app state loaded" Dec 18 05:49:47 bureau go-librespot[1340]: time="2025-12-18T05:49:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:49:47 bureau go-librespot[1340]: time="2025-12-18T05:49: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" Dec 18 05:49:47 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:47 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:49:47 bureau kernel: usb 1-1-port2: over-current change #299 Dec 18 05:49:47 bureau kernel: usb 1-1-port2: over-current change #300 Dec 18 05:49:48 bureau kernel: usb 1-1-port2: over-current change #301 Dec 18 05:49:48 bureau kernel: usb 1-1-port2: over-current change #302 Dec 18 05:49:48 bureau kernel: usb 1-1-port2: over-current change #303 Dec 18 05:49:49 bureau kernel: usb 1-1-port2: over-current change #304 Dec 18 05:49:49 bureau sudo[1349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 18 05:49:49 bureau sudo[1349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:49 bureau sudo[1351]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 18 05:49:49 bureau sudo[1351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:49:49 bureau kernel: usb 1-1-port2: over-current change #305 Dec 18 05:49:49 bureau systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 18 05:49:49 bureau mpd_monitor.sh[1354]: MPD Monitor Service: Starting MPD Monitor Service Dec 18 05:49:49 bureau systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 18 05:49:49 bureau sudo[1349]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:49 bureau systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 18 05:49:49 bureau systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 18 05:49:49 bureau systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 18 05:49:49 bureau mpd_monitor.sh[1357]: MPD Monitor Service: Starting MPD Monitor Service Dec 18 05:49:49 bureau sudo[1351]: pam_unix(sudo:session): session closed for user root Dec 18 05:49:49 bureau volumio[916]: info: Successfully started MPD Monitor Dec 18 05:49:49 bureau volumio[916]: info: Successfully started MPD Monitor Dec 18 05:49:49 bureau kernel: usb 1-1-port2: over-current change #306 Dec 18 05:49:49 bureau kernel: usb 1-1-port2: over-current change #307 Dec 18 05:49:50 bureau kernel: usb 1-1-port2: over-current change #308 Dec 18 05:49:50 bureau volumio[916]: info: Initializing connection to go-librespot Websocket Dec 18 05:49:50 bureau volumio[916]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 18 05:49:50 bureau kernel: usb 1-1-port2: over-current change #309 Dec 18 05:49:50 bureau kernel: usb 1-1-port2: over-current change #310 Dec 18 05:49:50 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 18 05:49:50 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:50 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:50 bureau go-librespot[1361]: go-librespot daemon starting... Dec 18 05:49:50 bureau kernel: usb 1-1-port2: over-current change #311 Dec 18 05:49:50 bureau go-librespot[1362]: time="2025-12-18T05:49:50+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:49:50 bureau go-librespot[1362]: time="2025-12-18T05:49:50+01:00" level=debug msg="app state loaded" Dec 18 05:49:50 bureau go-librespot[1362]: time="2025-12-18T05:49:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:49:50 bureau go-librespot[1362]: time="2025-12-18T05:49:50+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" Dec 18 05:49:50 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:50 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:49:51 bureau kernel: usb 1-1-port2: over-current change #312 Dec 18 05:49:51 bureau kernel: usb 1-1-port2: over-current change #313 Dec 18 05:49:51 bureau volumio[916]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 18 05:49:51 bureau volumio-remote-updater[576]: [2025-12-18 05:49:51] [connect] Successful connection Dec 18 05:49:51 bureau kernel: usb 1-1-port2: over-current change #314 Dec 18 05:49:51 bureau volumio-remote-updater[576]: [2025-12-18 05:49:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1766033391 101 Dec 18 05:49:51 bureau volumio[916]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Dec 18 05:49:51 bureau kernel: usb 1-1-port2: over-current change #315 Dec 18 05:49:52 bureau kernel: usb 1-1-port2: over-current change #316 Dec 18 05:49:52 bureau kernel: usb 1-1-port2: over-current change #317 Dec 18 05:49:52 bureau volumio[916]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.073&uuid=b6a44ecbdace7f4bb3ca2aaeb7f0eb43" http://updates.volumio.org/downloader-v1/track-device Dec 18 05:49:52 bureau volumio[916]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 18 05:49:52 bureau volumio[916]: Dload Upload Total Spent Left Speed Dec 18 05:49:52 bureau volumio[916]: [132B blob data] Dec 18 05:49:52 bureau volumio[916]: retrying in 5 seconds, trial 0 Dec 18 05:49:52 bureau volumio[916]: info: Volumio Calling Home Dec 18 05:49:52 bureau kernel: usb 1-1-port2: over-current change #318 Dec 18 05:49:52 bureau kernel: usb 1-1-port2: over-current change #319 Dec 18 05:49:53 bureau kernel: usb 1-1-port2: over-current change #320 Dec 18 05:49:53 bureau volumio[916]: info: Initializing connection to go-librespot Websocket Dec 18 05:49:53 bureau volumio[916]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 18 05:49:53 bureau kernel: usb 1-1-port2: over-current change #321 Dec 18 05:49:53 bureau kernel: usb 1-1-port2: over-current change #322 Dec 18 05:49:53 bureau kernel: usb 1-1-port2: over-current change #323 Dec 18 05:49:53 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 18 05:49:53 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:53 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:53 bureau go-librespot[1371]: go-librespot daemon starting... Dec 18 05:49:54 bureau go-librespot[1372]: time="2025-12-18T05:49:54+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:49:54 bureau go-librespot[1372]: time="2025-12-18T05:49:54+01:00" level=debug msg="app state loaded" Dec 18 05:49:54 bureau go-librespot[1372]: time="2025-12-18T05:49:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:49:54 bureau go-librespot[1372]: time="2025-12-18T05:49: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" Dec 18 05:49:54 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:54 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:49:54 bureau kernel: usb 1-1-port2: over-current change #324 Dec 18 05:49:54 bureau kernel: usb 1-1-port2: over-current change #325 Dec 18 05:49:54 bureau kernel: usb 1-1-port2: over-current change #326 Dec 18 05:49:54 bureau kernel: usb 1-1-port2: over-current change #327 Dec 18 05:49:55 bureau kernel: usb 1-1-port2: over-current change #328 Dec 18 05:49:55 bureau kernel: usb 1-1-port2: over-current change #329 Dec 18 05:49:55 bureau kernel: usb 1-1-port2: over-current change #330 Dec 18 05:49:55 bureau kernel: usb 1-1-port2: over-current change #331 Dec 18 05:49:56 bureau kernel: usb 1-1-port2: over-current change #332 Dec 18 05:49:56 bureau volumio[916]: info: Initializing connection to go-librespot Websocket Dec 18 05:49:56 bureau volumio[916]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 18 05:49:56 bureau kernel: usb 1-1-port2: over-current change #333 Dec 18 05:49:56 bureau kernel: usb 1-1-port2: over-current change #334 Dec 18 05:49:56 bureau kernel: usb 1-1-port2: over-current change #335 Dec 18 05:49:57 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 18 05:49:57 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:57 bureau kernel: usb 1-1-port2: over-current change #336 Dec 18 05:49:57 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:49:57 bureau go-librespot[1392]: go-librespot daemon starting... Dec 18 05:49:57 bureau go-librespot[1393]: time="2025-12-18T05:49:57+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:49:57 bureau go-librespot[1393]: time="2025-12-18T05:49:57+01:00" level=debug msg="app state loaded" Dec 18 05:49:57 bureau go-librespot[1393]: time="2025-12-18T05:49:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:49:57 bureau go-librespot[1393]: time="2025-12-18T05:49: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" Dec 18 05:49:57 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:49:57 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:49:57 bureau kernel: usb 1-1-port2: over-current change #337 Dec 18 05:49:57 bureau kernel: usb 1-1-port2: over-current change #338 Dec 18 05:49:58 bureau kernel: usb 1-1-port2: over-current change #339 Dec 18 05:49:58 bureau kernel: usb 1-1-port2: over-current change #340 Dec 18 05:49:58 bureau kernel: usb 1-1-port2: over-current change #341 Dec 18 05:49:58 bureau kernel: usb 1-1-port2: over-current change #342 Dec 18 05:49:59 bureau kernel: usb 1-1-port2: over-current change #343 Dec 18 05:49:59 bureau kernel: usb 1-1-port2: over-current change #344 Dec 18 05:49:59 bureau volumio[916]: info: Initializing connection to go-librespot Websocket Dec 18 05:49:59 bureau volumio[916]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 18 05:49:59 bureau kernel: usb 1-1-port2: over-current change #345 Dec 18 05:49:59 bureau kernel: usb 1-1-port2: over-current change #346 Dec 18 05:50:00 bureau kernel: usb 1-1-port2: over-current change #347 Dec 18 05:50:00 bureau kernel: usb 1-1-port2: over-current change #348 Dec 18 05:50:00 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 18 05:50:00 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:00 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:00 bureau go-librespot[1399]: go-librespot daemon starting... Dec 18 05:50:00 bureau go-librespot[1400]: time="2025-12-18T05:50:00+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:50:00 bureau go-librespot[1400]: time="2025-12-18T05:50:00+01:00" level=debug msg="app state loaded" Dec 18 05:50:00 bureau go-librespot[1400]: time="2025-12-18T05:50:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:50:00 bureau kernel: usb 1-1-port2: over-current change #349 Dec 18 05:50:00 bureau go-librespot[1400]: time="2025-12-18T05:50: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" Dec 18 05:50:00 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:50:00 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:50:00 bureau kernel: usb 1-1-port2: over-current change #350 Dec 18 05:50:01 bureau kernel: usb 1-1-port2: over-current change #351 Dec 18 05:50:01 bureau kernel: usb 1-1-port2: over-current change #352 Dec 18 05:50:01 bureau kernel: usb 1-1-port2: over-current change #353 Dec 18 05:50:01 bureau kernel: usb 1-1-port2: over-current change #354 Dec 18 05:50:01 bureau dhcpcd[691]: eth0: offered 192.168.10.101 from 192.168.10.254 Dec 18 05:50:01 bureau dhcpcd[691]: eth0: probing address 192.168.10.101/24 Dec 18 05:50:02 bureau kernel: usb 1-1-port2: over-current change #355 Dec 18 05:50:02 bureau volumio[916]: info: Initializing connection to go-librespot Websocket Dec 18 05:50:02 bureau kernel: usb 1-1-port2: over-current change #356 Dec 18 05:50:02 bureau volumio[916]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 18 05:50:02 bureau kernel: usb 1-1-port2: over-current change #357 Dec 18 05:50:02 bureau volumio[916]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.073&uuid=b6a44ecbdace7f4bb3ca2aaeb7f0eb43" http://updates.volumio.org/downloader-v1/track-device Dec 18 05:50:02 bureau volumio[916]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 18 05:50:02 bureau volumio[916]: Dload Upload Total Spent Left Speed Dec 18 05:50:02 bureau volumio[916]: [132B blob data] Dec 18 05:50:02 bureau volumio[916]: retrying in 5 seconds, trial 1 Dec 18 05:50:02 bureau volumio[916]: info: Volumio Calling Home Dec 18 05:50:02 bureau kernel: usb 1-1-port2: over-current change #358 Dec 18 05:50:03 bureau kernel: usb 1-1-port2: over-current change #359 Dec 18 05:50:03 bureau kernel: usb 1-1-port2: over-current change #360 Dec 18 05:50:03 bureau kernel: usb 1-1-port2: over-current change #361 Dec 18 05:50:03 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 18 05:50:03 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:03 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:03 bureau go-librespot[1409]: go-librespot daemon starting... Dec 18 05:50:03 bureau go-librespot[1410]: time="2025-12-18T05:50:03+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:50:03 bureau go-librespot[1410]: time="2025-12-18T05:50:03+01:00" level=debug msg="app state loaded" Dec 18 05:50:03 bureau go-librespot[1410]: time="2025-12-18T05:50:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:50:03 bureau go-librespot[1410]: time="2025-12-18T05:50:03+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" Dec 18 05:50:03 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:50:03 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:50:03 bureau kernel: usb 1-1-port2: over-current change #362 Dec 18 05:50:04 bureau kernel: usb 1-1-port2: over-current change #363 Dec 18 05:50:04 bureau kernel: usb 1-1-port2: over-current change #364 Dec 18 05:50:04 bureau kernel: usb 1-1-port2: over-current change #365 Dec 18 05:50:04 bureau kernel: usb 1-1-port2: over-current change #366 Dec 18 05:50:05 bureau kernel: usb 1-1-port2: over-current change #367 Dec 18 05:50:05 bureau volumio[916]: info: Initializing connection to go-librespot Websocket Dec 18 05:50:05 bureau volumio[916]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 18 05:50:05 bureau kernel: usb 1-1-port2: over-current change #368 Dec 18 05:50:05 bureau kernel: usb 1-1-port2: over-current change #369 Dec 18 05:50:05 bureau kernel: usb 1-1-port2: over-current change #370 Dec 18 05:50:06 bureau volumio[916]: error: MyVolumio Plugin failed to start in a timely fashion Dec 18 05:50:06 bureau volumio[916]: [Metrics] CommandRouter: 58s 651.80ms Dec 18 05:50:06 bureau volumio[916]: info: CoreCommandRouter::volumiosetStartupVolume Dec 18 05:50:06 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 05:50:06 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:50:06 bureau volumio[916]: info: CoreCommandRouter::Close All Modals sent Dec 18 05:50:06 bureau volumio[916]: info: CoreCommandRouter::Close All Modals sent Dec 18 05:50:06 bureau kernel: usb 1-1-port2: over-current change #371 Dec 18 05:50:06 bureau kernel: usb 1-1-port2: over-current change #372 Dec 18 05:50:06 bureau kernel: usb 1-1-port2: over-current change #373 Dec 18 05:50:06 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 18 05:50:06 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:06 bureau dhcpcd[691]: eth0: leased 192.168.10.101 for 86400 seconds Dec 18 05:50:06 bureau avahi-daemon[560]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.10.101. Dec 18 05:50:06 bureau dhcpcd[691]: eth0: adding route to 192.168.10.0/24 Dec 18 05:50:06 bureau avahi-daemon[560]: New relevant interface eth0.IPv4 for mDNS. Dec 18 05:50:06 bureau avahi-daemon[560]: Registering new address record for 192.168.10.101 on eth0.IPv4. Dec 18 05:50:06 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:07 bureau kernel: usb 1-1-port2: over-current change #374 Dec 18 05:50:07 bureau systemd[1]: Started nmbd.service - Samba NMB Daemon. Dec 18 05:50:07 bureau go-librespot[1432]: go-librespot daemon starting... Dec 18 05:50:07 bureau systemd[1]: Starting winbind.service - Samba Winbind Daemon... Dec 18 05:50:07 bureau systemd[1]: welcome.service: Deactivated successfully. Dec 18 05:50:07 bureau systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 18 05:50:07 bureau systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 18 05:50:07 bureau go-librespot[1440]: time="2025-12-18T05:50:07+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:50:07 bureau go-librespot[1440]: time="2025-12-18T05:50:07+01:00" level=debug msg="app state loaded" Dec 18 05:50:07 bureau systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 18 05:50:07 bureau go-librespot[1440]: time="2025-12-18T05:50:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:50:07 bureau welcome[1454]: Resolved ip:[1] 192.168.10.101 Dec 18 05:50:07 bureau dhcpcd[691]: eth0: adding default route via 192.168.10.254 Dec 18 05:50:07 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 18 05:50:07 bureau systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 18 05:50:07 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 18 05:50:07 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 18 05:50:07 bureau systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 18 05:50:07 bureau kernel: usb 1-1-port2: over-current change #375 Dec 18 05:50:07 bureau kernel: usb 1-1-port2: over-current change #376 Dec 18 05:50:07 bureau kernel: usb 1-1-port2: over-current change #377 Dec 18 05:50:07 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 18 05:50:07 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 05:50:07 bureau volumio[916]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 18 05:50:08 bureau kernel: usb 1-1-port2: over-current change #378 Dec 18 05:50:08 bureau ntpd[796]: IO: Listen normally on 3 eth0 192.168.10.101:123 Dec 18 05:50:08 bureau ntpd[796]: IO: new interface(s) found: waking up resolver Dec 18 05:50:08 bureau ntpd[796]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 18 05:50:08 bureau winbindd[1469]: [2025/12/18 05:50:08.099848, 0] ../../source3/winbindd/winbindd.c:1440(main) Dec 18 05:50:08 bureau winbindd[1469]: winbindd version 4.17.8-Raspbian started. Dec 18 05:50:08 bureau winbindd[1469]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 18 05:50:08 bureau winbindd[1469]: [2025/12/18 05:50:08.143994, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Dec 18 05:50:08 bureau winbindd[1469]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 18 05:50:08 bureau systemd[1]: Started winbind.service - Samba Winbind Daemon. Dec 18 05:50:08 bureau systemd[1]: Starting smbd.service - Samba SMB Daemon... Dec 18 05:50:08 bureau kernel: usb 1-1-port2: over-current change #379 Dec 18 05:50:08 bureau volumio[916]: info: Initializing connection to go-librespot Websocket Dec 18 05:50:08 bureau kernel: usb 1-1-port2: over-current change #380 Dec 18 05:50:08 bureau kernel: usb 1-1-port2: over-current change #381 Dec 18 05:50:09 bureau kernel: usb 1-1-port2: over-current change #382 Dec 18 05:50:09 bureau smbd[1480]: [2025/12/18 05:50:09.209621, 0] ../../source3/smbd/server.c:1741(main) Dec 18 05:50:09 bureau smbd[1480]: smbd version 4.17.8-Raspbian started. Dec 18 05:50:09 bureau smbd[1480]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 18 05:50:09 bureau kernel: usb 1-1-port2: over-current change #383 Dec 18 05:50:09 bureau kernel: usb 1-1-port2: over-current change #384 Dec 18 05:50:09 bureau kernel: usb 1-1-port2: over-current change #385 Dec 18 05:50:10 bureau kernel: usb 1-1-port2: over-current change #386 Dec 18 05:50:10 bureau kernel: usb 1-1-port2: over-current change #387 Dec 18 05:50:10 bureau kernel: usb 1-1-port2: over-current change #388 Dec 18 05:50:10 bureau kernel: usb 1-1-port2: over-current change #389 Dec 18 05:50:11 bureau kernel: usb 1-1-port2: over-current change #390 Dec 18 05:50:11 bureau kernel: usb 1-1-port2: over-current change #391 Dec 18 05:50:11 bureau systemd[1]: Started smbd.service - Samba SMB Daemon. Dec 18 05:50:11 bureau systemd[1]: Reached target multi-user.target - Multi-User System. Dec 18 05:50:11 bureau systemd[1]: Reached target graphical.target - Graphical Interface. Dec 18 05:50:11 bureau systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Dec 18 05:50:11 bureau kernel: usb 1-1-port2: over-current change #392 Dec 18 05:50:11 bureau systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Dec 18 05:50:11 bureau systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Dec 18 05:50:11 bureau systemd[1]: Startup finished in 19.303s (kernel) + 1min 27.424s (userspace) = 1min 46.728s. Dec 18 05:50:11 bureau kernel: usb 1-1-port2: over-current change #393 Dec 18 05:50:12 bureau kernel: usb 1-1-port2: over-current change #394 Dec 18 05:50:12 bureau kernel: usb 1-1-port2: over-current change #395 Dec 18 05:50:12 bureau kernel: usb 1-1-port2: over-current change #396 Dec 18 05:50:12 bureau kernel: usb 1-1-port2: over-current change #397 Dec 18 05:50:13 bureau volumio[916]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.073&uuid=b6a44ecbdace7f4bb3ca2aaeb7f0eb43" http://updates.volumio.org/downloader-v1/track-device Dec 18 05:50:13 bureau volumio[916]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 18 05:50:13 bureau volumio[916]: Dload Upload Total Spent Left Speed Dec 18 05:50:13 bureau volumio[916]: [132B blob data] Dec 18 05:50:13 bureau volumio[916]: retrying in 5 seconds, trial 2 Dec 18 05:50:13 bureau volumio[916]: info: Volumio Calling Home Dec 18 05:50:13 bureau kernel: usb 1-1-port2: over-current change #398 Dec 18 05:50:13 bureau volumio[916]: info: BOOT COMPLETED Dec 18 05:50:13 bureau kernel: usb 1-1-port2: over-current change #399 Dec 18 05:50:13 bureau kernel: usb 1-1-port2: over-current change #400 Dec 18 05:50:13 bureau kernel: usb 1-1-port2: over-current change #401 Dec 18 05:50:14 bureau kernel: usb 1-1-port2: over-current change #402 Dec 18 05:50:14 bureau kernel: usb 1-1-port2: over-current change #403 Dec 18 05:50:14 bureau kernel: usb 1-1-port2: over-current change #404 Dec 18 05:50:14 bureau kernel: usb 1-1-port2: over-current change #405 Dec 18 05:50:15 bureau kernel: usb 1-1-port2: over-current change #406 Dec 18 05:50:15 bureau volumio[916]: info: Volumio Network Manager: Network status updated: 1 Dec 18 05:50:15 bureau kernel: usb 1-1-port2: over-current change #407 Dec 18 05:50:15 bureau kernel: usb 1-1-port2: over-current change #408 Dec 18 05:50:15 bureau kernel: usb 1-1-port2: over-current change #409 Dec 18 05:50:16 bureau kernel: usb 1-1-port2: over-current change #410 Dec 18 05:50:16 bureau kernel: usb 1-1-port2: over-current change #411 Dec 18 05:50:16 bureau kernel: usb 1-1-port2: over-current change #412 Dec 18 05:50:17 bureau kernel: usb 1-1-port2: over-current change #413 Dec 18 05:50:17 bureau kernel: usb 1-1-port2: over-current change #414 Dec 18 05:50:17 bureau kernel: usb 1-1-port2: over-current change #415 Dec 18 05:50:17 bureau kernel: usb 1-1-port2: over-current change #416 Dec 18 05:50:18 bureau kernel: usb 1-1-port2: over-current change #417 Dec 18 05:50:18 bureau kernel: usb 1-1-port2: over-current change #418 Dec 18 05:50:18 bureau kernel: usb 1-1-port2: over-current change #419 Dec 18 05:50:18 bureau kernel: usb 1-1-port2: over-current change #420 Dec 18 05:50:19 bureau kernel: usb 1-1-port2: over-current change #421 Dec 18 05:50:19 bureau kernel: usb 1-1-port2: over-current change #422 Dec 18 05:50:19 bureau kernel: usb 1-1-port2: over-current change #423 Dec 18 05:50:19 bureau kernel: usb 1-1-port2: over-current change #424 Dec 18 05:50:20 bureau kernel: usb 1-1-port2: over-current change #425 Dec 18 05:50:20 bureau kernel: usb 1-1-port2: over-current change #426 Dec 18 05:50:20 bureau kernel: usb 1-1-port2: over-current change #427 Dec 18 05:50:20 bureau kernel: usb 1-1-port2: over-current change #428 Dec 18 05:50:21 bureau kernel: usb 1-1-port2: over-current change #429 Dec 18 05:50:21 bureau kernel: usb 1-1-port2: over-current change #430 Dec 18 05:50:21 bureau kernel: usb 1-1-port2: over-current change #431 Dec 18 05:50:21 bureau kernel: usb 1-1-port2: over-current change #432 Dec 18 05:50:22 bureau go-librespot[1440]: time="2025-12-18T05:50:22+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" Dec 18 05:50:22 bureau kernel: usb 1-1-port2: over-current change #433 Dec 18 05:50:22 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:50:22 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:50:22 bureau kernel: usb 1-1-port2: over-current change #434 Dec 18 05:50:22 bureau kernel: usb 1-1-port2: over-current change #435 Dec 18 05:50:22 bureau kernel: usb 1-1-port2: over-current change #436 Dec 18 05:50:23 bureau kernel: usb 1-1-port2: over-current change #437 Dec 18 05:50:23 bureau kernel: usb 1-1-port2: over-current change #438 Dec 18 05:50:23 bureau kernel: usb 1-1-port2: over-current change #439 Dec 18 05:50:23 bureau kernel: usb 1-1-port2: over-current change #440 Dec 18 05:50:24 bureau kernel: usb 1-1-port2: over-current change #441 Dec 18 05:50:24 bureau kernel: usb 1-1-port2: over-current change #442 Dec 18 05:50:24 bureau kernel: usb 1-1-port2: over-current change #443 Dec 18 05:50:24 bureau kernel: usb 1-1-port2: over-current change #444 Dec 18 05:50:25 bureau kernel: usb 1-1-port2: over-current change #445 Dec 18 05:50:25 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 18 05:50:25 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:25 bureau kernel: usb 1-1-port2: over-current change #446 Dec 18 05:50:25 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:25 bureau go-librespot[1534]: go-librespot daemon starting... Dec 18 05:50:25 bureau go-librespot[1535]: time="2025-12-18T05:50:25+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:50:25 bureau go-librespot[1535]: time="2025-12-18T05:50:25+01:00" level=debug msg="app state loaded" Dec 18 05:50:25 bureau go-librespot[1535]: time="2025-12-18T05:50:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:50:25 bureau kernel: usb 1-1-port2: over-current change #447 Dec 18 05:50:26 bureau kernel: usb 1-1-port2: over-current change #448 Dec 18 05:50:26 bureau kernel: usb 1-1-port2: over-current change #449 Dec 18 05:50:26 bureau kernel: usb 1-1-port2: over-current change #450 Dec 18 05:50:26 bureau kernel: usb 1-1-port2: over-current change #451 Dec 18 05:50:27 bureau kernel: usb 1-1-port2: over-current change #452 Dec 18 05:50:27 bureau kernel: usb 1-1-port2: over-current change #453 Dec 18 05:50:27 bureau kernel: usb 1-1-port2: over-current change #454 Dec 18 05:50:27 bureau kernel: usb 1-1-port2: over-current change #455 Dec 18 05:50:28 bureau kernel: usb 1-1-port2: over-current change #456 Dec 18 05:50:28 bureau kernel: usb 1-1-port2: over-current change #457 Dec 18 05:50:28 bureau kernel: usb 1-1-port2: over-current change #458 Dec 18 05:50:28 bureau kernel: usb 1-1-port2: over-current change #459 Dec 18 05:50:29 bureau kernel: usb 1-1-port2: over-current change #460 Dec 18 05:50:29 bureau kernel: usb 1-1-port2: over-current change #461 Dec 18 05:50:29 bureau kernel: usb 1-1-port2: over-current change #462 Dec 18 05:50:29 bureau kernel: usb 1-1-port2: over-current change #463 Dec 18 05:50:30 bureau kernel: usb 1-1-port2: over-current change #464 Dec 18 05:50:30 bureau kernel: usb 1-1-port2: over-current change #465 Dec 18 05:50:30 bureau kernel: usb 1-1-port2: over-current change #466 Dec 18 05:50:30 bureau kernel: usb 1-1-port2: over-current change #467 Dec 18 05:50:31 bureau kernel: usb 1-1-port2: over-current change #468 Dec 18 05:50:31 bureau kernel: usb 1-1-port2: over-current change #469 Dec 18 05:50:31 bureau kernel: usb 1-1-port2: over-current change #470 Dec 18 05:50:31 bureau kernel: usb 1-1-port2: over-current change #471 Dec 18 05:50:32 bureau kernel: usb 1-1-port2: over-current change #472 Dec 18 05:50:32 bureau kernel: usb 1-1-port2: over-current change #473 Dec 18 05:50:32 bureau kernel: usb 1-1-port2: over-current change #474 Dec 18 05:50:32 bureau kernel: usb 1-1-port2: over-current change #475 Dec 18 05:50:33 bureau kernel: usb 1-1-port2: over-current change #476 Dec 18 05:50:33 bureau kernel: usb 1-1-port2: over-current change #477 Dec 18 05:50:33 bureau kernel: usb 1-1-port2: over-current change #478 Dec 18 05:50:33 bureau kernel: usb 1-1-port2: over-current change #479 Dec 18 05:50:34 bureau kernel: usb 1-1-port2: over-current change #480 Dec 18 05:50:34 bureau kernel: usb 1-1-port2: over-current change #481 Dec 18 05:50:34 bureau kernel: usb 1-1-port2: over-current change #482 Dec 18 05:50:35 bureau kernel: usb 1-1-port2: over-current change #483 Dec 18 05:50:35 bureau kernel: usb 1-1-port2: over-current change #484 Dec 18 05:50:35 bureau kernel: usb 1-1-port2: over-current change #485 Dec 18 05:50:35 bureau kernel: usb 1-1-port2: over-current change #486 Dec 18 05:50:36 bureau kernel: usb 1-1-port2: over-current change #487 Dec 18 05:50:36 bureau kernel: usb 1-1-port2: over-current change #488 Dec 18 05:50:36 bureau kernel: usb 1-1-port2: over-current change #489 Dec 18 05:50:36 bureau kernel: usb 1-1-port2: over-current change #490 Dec 18 05:50:37 bureau kernel: usb 1-1-port2: over-current change #491 Dec 18 05:50:37 bureau kernel: usb 1-1-port2: over-current change #492 Dec 18 05:50:37 bureau kernel: usb 1-1-port2: over-current change #493 Dec 18 05:50:37 bureau kernel: usb 1-1-port2: over-current change #494 Dec 18 05:50:38 bureau kernel: usb 1-1-port2: over-current change #495 Dec 18 05:50:38 bureau kernel: usb 1-1-port2: over-current change #496 Dec 18 05:50:38 bureau kernel: usb 1-1-port2: over-current change #497 Dec 18 05:50:38 bureau kernel: usb 1-1-port2: over-current change #498 Dec 18 05:50:39 bureau kernel: usb 1-1-port2: over-current change #499 Dec 18 05:50:39 bureau kernel: usb 1-1-port2: over-current change #500 Dec 18 05:50:39 bureau kernel: usb 1-1-port2: over-current change #501 Dec 18 05:50:39 bureau kernel: usb 1-1-port2: over-current change #502 Dec 18 05:50:40 bureau kernel: usb 1-1-port2: over-current change #503 Dec 18 05:50:40 bureau kernel: usb 1-1-port2: over-current change #504 Dec 18 05:50:40 bureau kernel: usb 1-1-port2: over-current change #505 Dec 18 05:50:40 bureau kernel: usb 1-1-port2: over-current change #506 Dec 18 05:50:41 bureau kernel: usb 1-1-port2: over-current change #507 Dec 18 05:50:41 bureau kernel: usb 1-1-port2: over-current change #508 Dec 18 05:50:41 bureau kernel: usb 1-1-port2: over-current change #509 Dec 18 05:50:41 bureau kernel: usb 1-1-port2: over-current change #510 Dec 18 05:50:42 bureau kernel: usb 1-1-port2: over-current change #511 Dec 18 05:50:42 bureau kernel: usb 1-1-port2: over-current change #512 Dec 18 05:50:42 bureau kernel: usb 1-1-port2: over-current change #513 Dec 18 05:50:42 bureau kernel: usb 1-1-port2: over-current change #514 Dec 18 05:50:43 bureau kernel: usb 1-1-port2: over-current change #515 Dec 18 05:50:43 bureau kernel: usb 1-1-port2: over-current change #516 Dec 18 05:50:43 bureau kernel: usb 1-1-port2: over-current change #517 Dec 18 05:50:44 bureau kernel: usb 1-1-port2: over-current change #518 Dec 18 05:50:44 bureau kernel: usb 1-1-port2: over-current change #519 Dec 18 05:50:44 bureau kernel: usb 1-1-port2: over-current change #520 Dec 18 05:50:44 bureau kernel: usb 1-1-port2: over-current change #521 Dec 18 05:50:45 bureau kernel: usb 1-1-port2: over-current change #522 Dec 18 05:50:45 bureau ntpd[796]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 18 05:50:45 bureau ntpd[796]: DNS: dns_check: DNS error: -11, System error Dec 18 05:50:45 bureau ntpd[796]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Dec 18 05:50:45 bureau go-librespot[1535]: time="2025-12-18T05:50:45+01:00" level=debug msg="new websocket client" Dec 18 05:50:45 bureau volumio[916]: info: Connection to go-librespot Websocket established Dec 18 05:50:45 bureau volumio[916]: info: Discovery: adding a9714c50-d3dc-44cc-9759-8f7a1e2f027e Dec 18 05:50:45 bureau volumio[916]: info: Discovery: Found device Cuisine Dec 18 05:50:45 bureau volumio[916]: info: Discovery: Connecting to remote: 192.168.10.100 Dec 18 05:50:45 bureau volumio[916]: info: Discovery: this is already registered, 305f60fc-996a-4a9c-a11d-4b5e2f41942d Dec 18 05:50:45 bureau volumio[916]: info: Discovery: Found device Bureau Dec 18 05:50:45 bureau kernel: usb 1-1-port2: over-current change #523 Dec 18 05:50:45 bureau volumio[916]: info: CoreCommandRouter::volumioGetState Dec 18 05:50:45 bureau volumio[916]: info: CorePlayQueue::getTrack 0 Dec 18 05:50:45 bureau kernel: usb 1-1-port2: over-current change #524 Dec 18 05:50:45 bureau go-librespot[1535]: time="2025-12-18T05:50:45+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" Dec 18 05:50:45 bureau systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 18 05:50:45 bureau systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 18 05:50:45 bureau kernel: usb 1-1-port2: over-current change #525 Dec 18 05:50:46 bureau ntpd[796]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 18 05:50:46 bureau ntpd[796]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 193.121.15.225 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 156.106.214.52 Dec 18 05:50:46 bureau kernel: usb 1-1-port2: over-current change #526 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 109.68.160.220 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 178.215.228.24 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 2a00:7580:60:211::52 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 2a0d:5440::24 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 2a0e:f780:0:100::15 Dec 18 05:50:46 bureau ntpd[796]: DNS: Pool taking: 2a12:bec4:1821:25c::123 Dec 18 05:50:46 bureau ntpd[796]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Dec 18 05:50:46 bureau volumio[916]: info: Connection to go-librespot Websocket closed Dec 18 05:50:46 bureau kernel: usb 1-1-port2: over-current change #527 Dec 18 05:50:46 bureau volumio[916]: info: Discovery: Connected to remote: 192.168.10.100 Dec 18 05:50:46 bureau kernel: usb 1-1-port2: over-current change #528 Dec 18 05:50:46 bureau kernel: usb 1-1-port2: over-current change #529 Dec 18 05:50:47 bureau ntpd[796]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 18 05:50:47 bureau ntpd[796]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 18 05:50:47 bureau ntpd[796]: DNS: Pool taking: 91.181.42.222 Dec 18 05:50:47 bureau ntpd[796]: DNS: Pool taking: 45.87.78.35 Dec 18 05:50:47 bureau ntpd[796]: DNS: Pool taking: 45.87.76.3 Dec 18 05:50:47 bureau ntpd[796]: DNS: Pool skipping: 156.106.214.52 Dec 18 05:50:47 bureau ntpd[796]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Dec 18 05:50:47 bureau kernel: usb 1-1-port2: over-current change #530 Dec 18 05:50:47 bureau kernel: usb 1-1-port2: over-current change #531 Dec 18 05:50:47 bureau kernel: usb 1-1-port2: over-current change #532 Dec 18 05:50:47 bureau kernel: usb 1-1-port2: over-current change #533 Dec 18 05:50:48 bureau ntpd[796]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 18 05:50:48 bureau ntpd[796]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 18 05:50:48 bureau ntpd[796]: DNS: Pool skipping: 178.215.228.24 Dec 18 05:50:48 bureau ntpd[796]: DNS: Pool taking: 162.159.200.123 Dec 18 05:50:48 bureau ntpd[796]: DNS: Pool taking: 156.106.214.48 Dec 18 05:50:48 bureau ntpd[796]: DNS: Pool taking: 94.142.246.192 Dec 18 05:50:48 bureau ntpd[796]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Dec 18 05:50:48 bureau kernel: usb 1-1-port2: over-current change #534 Dec 18 05:50:48 bureau volumio[916]: verbose: New Socket.io Connection to 192.168.10.101:3000 from 192.168.10.100 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 18 05:50:48 bureau volumio[916]: info: Getting Spotify volume Dec 18 05:50:48 bureau kernel: usb 1-1-port2: over-current change #535 Dec 18 05:50:48 bureau volumio[916]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 05:50:48 bureau volumio[916]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 18 05:50:48 bureau volumio[916]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 18 05:50:48 bureau volumio[916]: errno: -111, Dec 18 05:50:48 bureau volumio[916]: code: 'ECONNREFUSED', Dec 18 05:50:48 bureau volumio[916]: syscall: 'connect', Dec 18 05:50:48 bureau volumio[916]: address: '127.0.0.1', Dec 18 05:50:48 bureau volumio[916]: port: 9879, Dec 18 05:50:48 bureau volumio[916]: response: undefined Dec 18 05:50:48 bureau volumio[916]: } Dec 18 05:50:48 bureau volumio[916]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 05:50:48 bureau kernel: usb 1-1-port2: over-current change #536 Dec 18 05:50:48 bureau systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 18 05:50:48 bureau systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:48 bureau systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 18 05:50:48 bureau go-librespot[1589]: go-librespot daemon starting... Dec 18 05:50:48 bureau kernel: usb 1-1-port2: over-current change #537 Dec 18 05:50:48 bureau go-librespot[1590]: time="2025-12-18T05:50:48+01:00" level=info msg="running go-librespot 0.4.0" Dec 18 05:50:48 bureau go-librespot[1590]: time="2025-12-18T05:50:48+01:00" level=debug msg="app state loaded" Dec 18 05:50:48 bureau go-librespot[1590]: time="2025-12-18T05:50:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 18 05:50:49 bureau kernel: usb 1-1-port2: over-current change #538 Dec 18 05:50:49 bureau kernel: usb 1-1-port2: over-current change #539 Dec 18 05:50:49 bureau kernel: usb 1-1-port2: over-current change #540 Dec 18 05:50:49 bureau kernel: usb 1-1-port2: over-current change #541 Dec 18 05:50:50 bureau kernel: usb 1-1-port2: over-current change #542 Dec 18 05:50:50 bureau kernel: usb 1-1-port2: over-current change #543 Dec 18 05:50:50 bureau kernel: usb 1-1-port2: over-current change #544 Dec 18 05:50:50 bureau kernel: usb 1-1-port2: over-current change #545 Dec 18 05:50:51 bureau kernel: usb 1-1-port2: over-current change #546 Dec 18 05:50:51 bureau kernel: usb 1-1-port2: over-current change #547 Dec 18 05:50:51 bureau kernel: usb 1-1-port2: over-current change #548 Dec 18 05:50:51 bureau kernel: usb 1-1-port2: over-current change #549 Dec 18 05:50:52 bureau kernel: usb 1-1-port2: over-current change #550 Dec 18 05:50:52 bureau kernel: usb 1-1-port2: over-current change #551 Dec 18 05:50:52 bureau kernel: usb 1-1-port2: over-current change #552 Dec 18 05:50:53 bureau kernel: usb 1-1-port2: over-current change #553 Dec 18 05:50:53 bureau kernel: usb 1-1-port2: over-current change #554 Dec 18 05:50:53 bureau kernel: usb 1-1-port2: over-current change #555 Dec 18 05:50:53 bureau kernel: usb 1-1-port2: over-current change #556 Dec 18 05:50:54 bureau kernel: usb 1-1-port2: over-current change #557 Dec 18 05:50:54 bureau kernel: usb 1-1-port2: over-current change #558 Dec 18 05:50:54 bureau kernel: usb 1-1-port2: over-current change #559 Dec 18 05:50:54 bureau kernel: usb 1-1-port2: over-current change #560 Dec 18 05:50:55 bureau kernel: usb 1-1-port2: over-current change #561 Dec 18 05:50:55 bureau kernel: usb 1-1-port2: over-current change #562 Dec 18 05:50:55 bureau kernel: usb 1-1-port2: over-current change #563 Dec 18 05:50:55 bureau kernel: usb 1-1-port2: over-current change #564 Dec 18 05:50:56 bureau kernel: usb 1-1-port2: over-current change #565 Dec 18 05:50:56 bureau kernel: usb 1-1-port2: over-current change #566 Dec 18 05:50:56 bureau kernel: usb 1-1-port2: over-current change #567 Dec 18 05:50:56 bureau kernel: usb 1-1-port2: over-current change #568 Dec 18 05:50:56 bureau sudo[1624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-18 05:49' Dec 18 05:50:56 bureau sudo[1624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 05:50:57 bureau kernel: usb 1-1-port2: over-current change #569 Dec 18 05:50:57 bureau kernel: usb 1-1-port2: over-current change #570 Dec 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+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 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+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 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+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 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+01:00" level=info msg="zeroconf server listening on port 42939" Dec 18 05:50:57 bureau kernel: usb 1-1-port2: over-current change #571 Dec 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+01:00" level=debug msg="obtained new client token: AACSrukOp3cUBM2UA9v32g5FEHneGg3BdC59Q9PD+v51vQJjb8lFnIN+4M6vs2lfzASNJwp0G9oyA5oQco546zi9OalGFf3GpVs9G71wBsF/aybI4/D6BmaaYNgHiLc2upR9e80mxyjcaDq3yP4DPJR8RmgHAJh2JCoJjVXEG99c9jXRHxP9B1VnB6dulh+xytk0aSPWyYw4/ioM67I7XKqtEfNVNOf9MHEMlUSt+zDlhouLyuM1voticw==" Dec 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+01:00" level=debug msg="completed keyexchange" Dec 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+01:00" level=debug msg="completed challenge" Dec 18 05:50:57 bureau kernel: usb 1-1-port2: over-current change #572 Dec 18 05:50:57 bureau go-librespot[1590]: time="2025-12-18T05:50:57+01:00" level=info msg="authenticated AP" username="le******te" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=info msg="authenticated Login5" username="le******te" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="initializing zeroconf session" username="le******te" Dec 18 05:50:58 bureau kernel: usb 1-1-port2: over-current change #573 Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="dealer connection opened" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=trace msg="starting accesspoint recv loop" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=trace msg="starting dealer recv loop" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=trace msg="received accesspoint ping" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="received connection id: ZmQzZDlkNDEtZmU0...NDRDREYzNjQzMw==" Dec 18 05:50:58 bureau kernel: usb 1-1-port2: over-current change #574 Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="update volume requested to 56360/65535" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=trace msg="received accesspoint pong ack" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 18 05:50:58 bureau go-librespot[1590]: time="2025-12-18T05:50:58+01:00" level=trace msg="emitting websocket event: volume" Dec 18 05:50:58 bureau kernel: usb 1-1-port2: over-current change #575 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"