Aug 30 11:28:00 volumio winbindd[1152]: [2026/08/30 11:28:00.060078, 0] ../../source3/winbindd/winbindd_cache.c:3117(initialize_winbindd_cache)
Aug 30 11:28:00 volumio winbindd[1152]: initialize_winbindd_cache: clearing cache and re-creating with version number 2
Aug 30 11:28:00 volumio volumio-cpu-tweak[1175]: Setting RT Priority for mpd
Aug 30 11:28:00 volumio systemd[1]: Started winbind.service - Samba Winbind Daemon.
Aug 30 11:28:00 volumio systemd[1]: Starting smbd.service - Samba SMB Daemon...
Aug 30 11:28:00 volumio volumio-cpu-tweak[1201]: pid 35's current scheduling policy: SCHED_OTHER
Aug 30 11:28:00 volumio volumio-cpu-tweak[1201]: pid 35's current scheduling priority: 0
Aug 30 11:28:00 volumio volumio-cpu-tweak[1175]: Not enough cores to set MPD affinity
Aug 30 11:28:00 volumio volumio-cpu-tweak[1175]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance
Aug 30 11:28:00 volumio volumio-cpu-tweak[1205]: Error setting new values. Common errors:
Aug 30 11:28:00 volumio volumio-cpu-tweak[1205]: - Do you have proper administration rights? (super-user?)
Aug 30 11:28:00 volumio volumio-cpu-tweak[1205]: - Is the governor you requested available and modprobed?
Aug 30 11:28:00 volumio volumio-cpu-tweak[1205]: - Trying to set an invalid policy?
Aug 30 11:28:00 volumio volumio-cpu-tweak[1205]: - Trying to set a specific frequency, but userspace governor is not available,
Aug 30 11:28:00 volumio volumio-cpu-tweak[1205]: for example because of hardware which cannot be set to a specific frequency
Aug 30 11:28:00 volumio volumio-cpu-tweak[1205]: or because the userspace governor isn't loaded?
Aug 30 11:28:01 volumio systemd[1]: volumio_cpu_tweak.service: Deactivated successfully.
Aug 30 11:28:02 volumio smbd[1211]: [2026/08/30 11:28:02.193015, 0] ../../source3/smbd/server.c:1741(main)
Aug 30 11:28:02 volumio smbd[1211]: smbd version 4.17.12-Debian started.
Aug 30 11:28:02 volumio smbd[1211]: Copyright Andrew Tridgell and the Samba Team 1992-2022
Aug 30 11:28:02 volumio soundcard-init.sh[1241]: Card 0 Chip Realtek Generic Name HDA Intel PCH
Aug 30 11:28:02 volumio soundcard-init.sh[1263]: Simple mixer control 'Master',0
Aug 30 11:28:02 volumio soundcard-init.sh[1263]: Capabilities: pvolume pvolume-joined pswitch pswitch-joined
Aug 30 11:28:02 volumio soundcard-init.sh[1263]: Playback channels: Mono
Aug 30 11:28:02 volumio soundcard-init.sh[1263]: Limits: Playback 0 - 64
Aug 30 11:28:02 volumio soundcard-init.sh[1263]: Mono: Playback 48 [75%] [-16.00dB] [on]
Aug 30 11:28:02 volumio systemd[1]: soundcard-init.service: Deactivated successfully.
Aug 30 11:28:03 volumio startx[1273]: X.Org X Server 1.21.1.7
Aug 30 11:28:03 volumio startx[1273]: X Protocol Version 11, Revision 0
Aug 30 11:28:03 volumio startx[1273]: Current Operating System: Linux volumio 6.12.57-volumio #2 SMP PREEMPT_DYNAMIC Thu Nov 13 17:08:37 CET 2025 x86_64
Aug 30 11:28:03 volumio startx[1273]: Kernel command line: BOOT_IMAGE=vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 bootdelay=5 biosdevname=0 imgpart=UUID=3f06cc5a-6a9b-457e-a762-7ec23630efac bootpart=UUID=6218-8677 datapart=UUID=1ceb5326-9335-4ddc-b585-cf0d63bb20ab hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=native net.ifnames=0 use_kmsg=no initrd=volumio.initrd
Aug 30 11:28:03 volumio startx[1273]: xorg-server 2:21.1.7-3+deb12u11 (https://www.debian.org/support)
Aug 30 11:28:03 volumio startx[1273]: Current version of pixman: 0.42.2
Aug 30 11:28:03 volumio startx[1273]: Before reporting problems, check http://wiki.x.org
Aug 30 11:28:03 volumio startx[1273]: to make sure that you have the latest version.
Aug 30 11:28:03 volumio startx[1273]: Markers: (--) probed, (**) from config file, (==) default setting,
Aug 30 11:28:03 volumio startx[1273]: (++) from command line, (!!) notice, (II) informational,
Aug 30 11:28:03 volumio startx[1273]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown.
Aug 30 11:28:03 volumio startx[1273]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Aug 30 11:28:03 2026
Aug 30 11:28:03 volumio startx[1273]: (==) Using system config directory "/usr/share/X11/xorg.conf.d"
Aug 30 11:28:03 volumio volumio-remote-updater[719]: [2026-08-30 11:28:03] [info] asio async_connect error: asio.system:111 (Connection refused)
Aug 30 11:28:03 volumio volumio-remote-updater[719]: [2026-08-30 11:28:03] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected)
Aug 30 11:28:03 volumio volumio-remote-updater[719]: [2026-08-30 11:28:03] [error] handle_connect error: Connection refused
Aug 30 11:28:04 volumio systemd[1]: Started smbd.service - Samba SMB Daemon.
Aug 30 11:28:04 volumio systemd[1]: Reached target multi-user.target - Multi-User System.
Aug 30 11:28:04 volumio systemd[1]: Reached target graphical.target - Graphical Interface.
Aug 30 11:28:04 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP...
Aug 30 11:28:04 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully.
Aug 30 11:28:04 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP.
Aug 30 11:28:04 volumio systemd[1]: Startup finished in 28.808s (kernel) + 21.012s (userspace) = 49.820s.
Aug 30 11:28:04 volumio startx[1273]: pci id for fd 16: 1234:1111, driver (null)
Aug 30 11:28:04 volumio startx[1273]: MESA-LOADER: failed to open bochs-drm: /usr/lib/dri/bochs-drm_dri.so: cannot open shared object file: No such file or directory (search paths /usr/lib/x86_64-linux-gnu/dri:\$${ORIGIN}/dri:/usr/lib/dri, suffix _dri)
Aug 30 11:28:04 volumio startx[1273]: failed to load driver: bochs-drm
Aug 30 11:28:07 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1.
Aug 30 11:28:07 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:07 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:07 volumio upmpdcli[1284]: Could not open config: /tmp/upmpdcli.conf
Aug 30 11:28:07 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:28:07 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 30 11:28:13 volumio volumio-remote-updater[719]: [2026-08-30 11:28:13] [connect] Successful connection
Aug 30 11:28:15 volumio startx[1273]: pci id for fd 17: 1234:1111, driver (null)
Aug 30 11:28:15 volumio startx[1273]: kmsro: driver missing
Aug 30 11:28:16 volumio volumio[1163]: info: -------------------------------------------
Aug 30 11:28:16 volumio volumio[1163]: info: ----- Volumio3 ----
Aug 30 11:28:16 volumio volumio[1163]: info: -------------------------------------------
Aug 30 11:28:16 volumio volumio[1163]: info: ----- System startup ----
Aug 30 11:28:16 volumio volumio[1163]: info: -------------------------------------------
Aug 30 11:28:16 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully.
Aug 30 11:28:16 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Aug 30 11:28:22 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2.
Aug 30 11:28:22 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:22 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:22 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Aug 30 11:28:22 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Aug 30 11:28:22 volumio upmpdcli[1352]: Could not open config: /tmp/upmpdcli.conf
Aug 30 11:28:22 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:28:22 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 30 11:28:23 volumio volumio[1163]: info: MYVOLUMIO Environment detected
Aug 30 11:28:25 volumio volumio[1163]: info: Plugin folders cleanup
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning into folder /volumio/app/plugins/
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning category audio_interface
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning category miscellanea
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning category music_service
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning category plugins.json
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning category system_controller
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning category user_interface
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning into folder /data/plugins/
Aug 30 11:28:25 volumio volumio[1163]: info: Scanning category music_service
Aug 30 11:28:25 volumio volumio[1163]: info: Plugin folders cleanup completed
Aug 30 11:28:25 volumio volumio[1163]: info: -------------------------------------------
Aug 30 11:28:25 volumio volumio[1163]: info: ----- Core plugins startup ----
Aug 30 11:28:25 volumio volumio[1163]: info: -------------------------------------------
Aug 30 11:28:25 volumio volumio[1163]: info: Loading plugins from folder /volumio/app/plugins/
Aug 30 11:28:25 volumio volumio[1163]: info: Adding plugin upnp to MyMusic Plugins
Aug 30 11:28:25 volumio volumio[1163]: info: Adding plugin airplay_emulation to MyMusic Plugins
Aug 30 11:28:25 volumio volumio[1163]: info: Adding plugin upnp_browser to MyMusic Plugins
Aug 30 11:28:25 volumio volumio[1163]: info: Loading plugins from folder /data/plugins/
Aug 30 11:28:25 volumio volumio[1163]: info: Loading plugin "system"...
Aug 30 11:28:25 volumio volumio[1163]: info: Loading plugin "appearance"...
Aug 30 11:28:28 volumio volumio-remote-updater[719]: [2026-08-30 11:28:28] [connect] Successful connection
Aug 30 11:28:34 volumio volumio[1163]: info: Loading plugin "network"...
Aug 30 11:28:34 volumio volumio[1163]: info: Refreshing Cached IP Addresses
Aug 30 11:28:34 volumio volumio[1163]: info: Loading plugin "services"...
Aug 30 11:28:34 volumio volumio[1163]: info: Loading plugin "volumio5onboarding"...
Aug 30 11:28:34 volumio volumio[1163]: info: Loading plugin "alsa_controller"...
Aug 30 11:28:34 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 30 11:28:34 volumio volumio[1163]: info: Loading plugin "wizard"...
Aug 30 11:28:34 volumio volumio[1163]: info: Loading plugin "networkfs"...
Aug 30 11:28:35 volumio sudo[1446]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Aug 30 11:28:35 volumio sudo[1457]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Aug 30 11:28:35 volumio sudo[1443]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Aug 30 11:28:35 volumio sudo[1446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:28:35 volumio sudo[1457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:28:35 volumio sudo[1443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:28:35 volumio sudo[1443]: pam_unix(sudo:session): session closed for user root
Aug 30 11:28:35 volumio sudo[1446]: pam_unix(sudo:session): session closed for user root
Aug 30 11:28:35 volumio sudo[1457]: pam_unix(sudo:session): session closed for user root
Aug 30 11:28:35 volumio sudo[1485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=wirewalker,password=Sousou32,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.2.21/DOWNLOAD/AUDIO/Music/ /mnt/NAS/MUSIC
Aug 30 11:28:35 volumio sudo[1485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:28:35 volumio volumio[1163]: info: Starting Udev Watcher for removable devices
Aug 30 11:28:35 volumio sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=wirewalker,password=Sousou32,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.2.21/DOWNLOAD/AUDIO/Coran/ /mnt/NAS/CORAN
Aug 30 11:28:35 volumio sudo[1491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=wirewalker,password=Sousou32,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.2.21/DOWNLOAD/AUDIO/Livres/ /mnt/NAS/Livres
Aug 30 11:28:35 volumio sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:28:35 volumio sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:28:35 volumio volumio[1163]: info: Ignoring mount for partition: boot
Aug 30 11:28:35 volumio volumio[1163]: info: Ignoring mount for partition: volumio
Aug 30 11:28:35 volumio volumio[1163]: info: Ignoring mount for partition: volumio_data
Aug 30 11:28:35 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Aug 30 11:28:35 volumio volumio[1163]: info: Loading plugin "volumio_command_line_client"...
Aug 30 11:28:35 volumio volumio[1163]: info: Loading plugin "upnp"...
Aug 30 11:28:35 volumio volumio[1163]: info: [1788085715680] Starting Upmpd Daemon
Aug 30 11:28:35 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Aug 30 11:28:35 volumio volumio[1163]: info: Loading plugin "my_music"...
Aug 30 11:28:35 volumio kernel: netfs: FS-Cache loaded
Aug 30 11:28:35 volumio kernel: Key type dns_resolver registered
Aug 30 11:28:35 volumio volumio[1163]: info: Loading plugin "mpd"...
Aug 30 11:28:36 volumio kernel: Key type cifs.spnego registered
Aug 30 11:28:36 volumio kernel: Key type cifs.idmap registered
Aug 30 11:28:36 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount.
Aug 30 11:28:36 volumio kernel: CIFS: Attempting to mount //192.168.2.21/DOWNLOAD/AUDIO/Livres
Aug 30 11:28:37 volumio volumio[1163]: info: Loading plugin "upnp_browser"...
Aug 30 11:28:37 volumio sudo[1491]: pam_unix(sudo:session): session closed for user root
Aug 30 11:28:37 volumio kernel: CIFS: Attempting to mount //192.168.2.21/DOWNLOAD/AUDIO/Music
Aug 30 11:28:37 volumio sudo[1485]: pam_unix(sudo:session): session closed for user root
Aug 30 11:28:37 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3.
Aug 30 11:28:37 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:37 volumio kernel: CIFS: Attempting to mount //192.168.2.21/DOWNLOAD/AUDIO/Coran
Aug 30 11:28:37 volumio sudo[1487]: pam_unix(sudo:session): session closed for user root
Aug 30 11:28:37 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:37 volumio upmpdcli[1543]: Could not open config: /tmp/upmpdcli.conf
Aug 30 11:28:37 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:28:37 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 30 11:28:39 volumio volumio[1163]: info: Starting UPNP Browser
Aug 30 11:28:39 volumio volumio[1163]: info: Loading plugin "alarm-clock"...
Aug 30 11:28:40 volumio volumio[1163]: info: Loading plugin "airplay_emulation"...
Aug 30 11:28:40 volumio volumio[1163]: info: Starting Shairport Sync
Aug 30 11:28:40 volumio volumio[1163]: info: Loading plugin "last_100"...
Aug 30 11:28:40 volumio volumio[1163]: info: Loading plugin "webradio"...
Aug 30 11:28:40 volumio volumio[1163]: info: Loading plugin "i2s_dacs"...
Aug 30 11:28:40 volumio volumio[1163]: info: I2S DAC not set, start Auto-detection
Aug 30 11:28:40 volumio volumio[1163]: info: Loading plugin "volumiodiscovery"...
Aug 30 11:28:41 volumio volumio[1163]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Aug 30 11:28:41 volumio node[1163]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Aug 30 11:28:41 volumio volumio[1163]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 30 11:28:41 volumio volumio[1163]: *** WARNING *** For more information see
Aug 30 11:28:41 volumio volumio[1163]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Aug 30 11:28:41 volumio volumio[1163]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 30 11:28:41 volumio volumio[1163]: *** WARNING *** For more information see
Aug 30 11:28:41 volumio node[1163]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 30 11:28:41 volumio node[1163]: *** WARNING *** For more information see
Aug 30 11:28:41 volumio node[1163]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Aug 30 11:28:41 volumio node[1163]: *** WARNING *** Please fix your application to use the native API of Avahi!
Aug 30 11:28:41 volumio node[1163]: *** WARNING *** For more information see
Aug 30 11:28:41 volumio volumio[1163]: info: Applying required configuration parameters for plugin volumiodiscovery
Aug 30 11:28:41 volumio volumio[1163]: info: Discovery: Started advertising with name: Volumio
Aug 30 11:28:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Aug 30 11:28:41 volumio volumio[1163]: info: Loading plugin "spop"...
Aug 30 11:28:43 volumio dbus-daemon[711]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.8' (uid=0 pid=1388 comm="/usr/lib/chromium/chromium --show-component-extens")
Aug 30 11:28:43 volumio systemd[1]: Starting bluetooth.service - Bluetooth service...
Aug 30 11:28:43 volumio volumio-remote-updater[719]: [2026-08-30 11:28:43] [connect] Successful connection
Aug 30 11:28:44 volumio kernel: Bluetooth: Core ver 2.22
Aug 30 11:28:44 volumio kernel: NET: Registered PF_BLUETOOTH protocol family
Aug 30 11:28:44 volumio kernel: Bluetooth: HCI device and connection manager initialized
Aug 30 11:28:44 volumio kernel: Bluetooth: HCI socket layer initialized
Aug 30 11:28:44 volumio kernel: Bluetooth: L2CAP socket layer initialized
Aug 30 11:28:44 volumio kernel: Bluetooth: SCO socket layer initialized
Aug 30 11:28:44 volumio bluetoothd[1566]: Bluetooth daemon 5.83
Aug 30 11:28:44 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Aug 30 11:28:44 volumio kernel: Bluetooth: BNEP filters: protocol multicast
Aug 30 11:28:44 volumio kernel: Bluetooth: BNEP socket layer initialized
Aug 30 11:28:44 volumio dbus-daemon[711]: [system] Successfully activated service 'org.bluez'
Aug 30 11:28:44 volumio systemd[1]: Started bluetooth.service - Bluetooth service.
Aug 30 11:28:44 volumio bluetoothd[1566]: Starting SDP server
Aug 30 11:28:44 volumio bluetoothd[1566]: Excluding (cli) sap
Aug 30 11:28:44 volumio bluetoothd[1566]: Excluding (cli) scanparam
Aug 30 11:28:44 volumio bluetoothd[1566]: Excluding (cli) midi
Aug 30 11:28:44 volumio bluetoothd[1566]: Excluding (cli) battery
Aug 30 11:28:44 volumio bluetoothd[1566]: Bluetooth management interface 1.23 initialized
Aug 30 11:28:44 volumio dbus-daemon[711]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.11' (uid=0 pid=1566 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b")
Aug 30 11:28:44 volumio systemd[1]: Starting systemd-hostnamed.service - Hostname Service...
Aug 30 11:28:44 volumio dbus-daemon[711]: [system] Successfully activated service 'org.freedesktop.hostname1'
Aug 30 11:28:44 volumio systemd[1]: Started systemd-hostnamed.service - Hostname Service.
Aug 30 11:28:52 volumio volumio[1163]: info: Loading plugin "youtube2"...
Aug 30 11:28:53 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4.
Aug 30 11:28:53 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:53 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:28:53 volumio upmpdcli[1719]: Could not open config: /tmp/upmpdcli.conf
Aug 30 11:28:53 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:28:53 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 30 11:28:58 volumio volumio[1163]: info: Plugin ytcr is not enabled
Aug 30 11:28:58 volumio volumio[1163]: info: Loading plugin "ytmusic"...
Aug 30 11:28:58 volumio volumio-remote-updater[719]: [2026-08-30 11:28:58] [connect] Successful connection
Aug 30 11:29:02 volumio volumio[1163]: info: Loading plugin "outputs"...
Aug 30 11:29:02 volumio volumio[1163]: info: Loading plugin "albumart"...
Aug 30 11:29:02 volumio volumio[1163]: info: Plugin example_plugin is not enabled
Aug 30 11:29:02 volumio volumio[1163]: info: Loading plugin "inputs"...
Aug 30 11:29:02 volumio volumio[1163]: info: Loading plugin "updater_comm"...
Aug 30 11:29:02 volumio volumio[1764]: Forking 1 albumart workers
Aug 30 11:29:02 volumio volumio[1163]: info: Plugin mpdemulation is not enabled
Aug 30 11:29:02 volumio volumio[1163]: info: Loading plugin "rest_api"...
Aug 30 11:29:02 volumio volumio[1163]: info: Loading plugin "websocket"...
Aug 30 11:29:02 volumio volumio[1163]: info: Starting Socket.io Server version 1.7.4
Aug 30 11:29:02 volumio volumio[1163]: info: Loading i18n strings for locale fr
Aug 30 11:29:02 volumio volumio[1163]: Updating browse sources language
Aug 30 11:29:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:03 volumio volumio[1774]: Starting albumart workers
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::initPlayerControls
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: Express server listening on port 3000
Aug 30 11:29:03 volumio volumio[1163]: [Metrics] WebUI: 50s 393.90ms
Aug 30 11:29:03 volumio volumio[1163]: info: Setting Device type: x86
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::resetVolumioState
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::getcurrentVolume
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioRetrievevolume
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt'
Aug 30 11:29:03 volumio volumio[1163]: info: Completed loading Core Plugins
Aug 30 11:29:03 volumio volumio[1163]: info: Preparing to generate the ALSA configuration file
Aug 30 11:29:03 volumio volumio[1163]: info: Volumio Network Manager: Network status updated: 1
Aug 30 11:29:03 volumio sudo[1793]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Aug 30 11:29:03 volumio sudo[1794]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Aug 30 11:29:03 volumio sudo[1794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1793]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio volumio[1163]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
Aug 30 11:29:03 volumio volumio[1163]: wlan0 Interface doesn't support scanning.
Aug 30 11:29:03 volumio volumio[1163]: info: Cannot use regular scanning, forcing with ap-force
Aug 30 11:29:03 volumio sudo[1794]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio sudo[1802]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
Aug 30 11:29:03 volumio sudo[1802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1802]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio volumio[1163]: command failed: No such device (-19)
Aug 30 11:29:03 volumio volumio[1163]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force
Aug 30 11:29:03 volumio volumio[1163]: command failed: No such device (-19)
Aug 30 11:29:03 volumio volumio[1163]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision
Aug 30 11:29:03 volumio volumio[1163]: info: VolumeController:: Volume=50 Mute =false
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::pushState
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::updateTrackBlock
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrackBlock
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioRetrievevolume
Aug 30 11:29:03 volumio volumio[1163]: info: Asound.conf file unchanged, so no further update is needed
Aug 30 11:29:03 volumio volumio[1163]: info: Output device has changed, restarting MPD
Aug 30 11:29:03 volumio volumio[1163]: info: Output device has changed, restarting Shairport Sync
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:03 volumio sudo[1817]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Aug 30 11:29:03 volumio sudo[1817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Aug 30 11:29:03 volumio sudo[1819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1817]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio volumio[1163]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 30 11:29:03 volumio volumio[1163]: info: ___________ START PLUGINS ___________
Aug 30 11:29:03 volumio volumio[1163]: info: ControllerMpd::onStart: Initializing MPD
Aug 30 11:29:03 volumio volumio[1163]: info: Creating MPD Configuration file
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 30 11:29:03 volumio sudo[1827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service
Aug 30 11:29:03 volumio sudo[1827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 30 11:29:03 volumio volumio[1163]: info: [1788085743331] CoreMusicLibrary::Adding element Serveurs Média
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:03 volumio sudo[1830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Aug 30 11:29:03 volumio sudo[1832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Aug 30 11:29:03 volumio volumio[1163]: info: UPNP Browser: Client initialized successfully
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Aug 30 11:29:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Aug 30 11:29:03 volumio sudo[1830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1830]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Aug 30 11:29:03 volumio sudo[1827]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio systemd[1]: mpd.service: Deactivated successfully.
Aug 30 11:29:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Aug 30 11:29:03 volumio systemd[1]: mpd.socket: Deactivated successfully.
Aug 30 11:29:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Aug 30 11:29:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Aug 30 11:29:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Aug 30 11:29:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Aug 30 11:29:03 volumio volumio[1163]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 30 11:29:03 volumio volumio[1163]: info: [1788085743406] CoreMusicLibrary::Adding element Last_100
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 30 11:29:03 volumio volumio[1163]: info: [1788085743407] CoreMusicLibrary::Adding element Webradio
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 30 11:29:03 volumio volumio[1163]: info: Initializing BBC Radios
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:03 volumio sudo[1843]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Aug 30 11:29:03 volumio sudo[1843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 30 11:29:03 volumio volumio[1163]: info: Creating Spotify config file
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio sudo[1861]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
Aug 30 11:29:03 volumio sudo[1843]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 30 11:29:03 volumio volumio[1163]: info: [1788085743606] CoreMusicLibrary::Adding element YouTube2
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:03 volumio volumio[1163]: Cannot find translation for source YouTube2
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 30 11:29:03 volumio volumio[1163]: info: [1788085743635] CoreMusicLibrary::Adding element YouTube Music
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:03 volumio volumio[1163]: Cannot find translation for source YouTube2
Aug 30 11:29:03 volumio volumio[1163]: Cannot find translation for source YouTube Music
Aug 30 11:29:03 volumio volumio[1163]: info: Volumio Calling Home
Aug 30 11:29:03 volumio volumio[1163]: info: Reloading queue from file
Aug 30 11:29:03 volumio volumio[1163]: info: MPD Permissions set
Aug 30 11:29:03 volumio volumio[1163]: info: MPD Permissions set
Aug 30 11:29:03 volumio volumio[1163]: info: VolumeController:: Volume=50 Mute =false
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::pushState
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::setRepeat true single undefined
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::pushState
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::setRandom null
Aug 30 11:29:03 volumio volumio[1163]: info: CoreStateMachine::pushState
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState
Aug 30 11:29:03 volumio volumio[1163]: info: Spotify config file written
Aug 30 11:29:03 volumio volumio[1163]: info: No need to fix Spotify hosts
Aug 30 11:29:03 volumio volumio-remote-updater[719]: [2026-08-30 11:29:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788085738 101
Aug 30 11:29:03 volumio volumio[1163]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1
Aug 30 11:29:03 volumio sudo[1870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Aug 30 11:29:03 volumio sudo[1870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio volumio[1163]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Aug 30 11:29:03 volumio sudo[1875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Aug 30 11:29:03 volumio sudo[1875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Aug 30 11:29:03 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Aug 30 11:29:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:03 volumio sudo[1875]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:03 volumio go-librespot[1887]: go-librespot daemon starting...
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:29:03 volumio volumio[1163]: info: Discovery: adding 33b20e60-4e68-48d5-beab-6103d46cab71
Aug 30 11:29:03 volumio volumio[1163]: info: Discovery: Found device Volumio
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:03 volumio volumio[1163]: info: Starting Shairport Sync
Aug 30 11:29:03 volumio volumio[1163]: info: Starting Shairport Sync
Aug 30 11:29:03 volumio volumio[1163]: info: Starting Shairport Sync
Aug 30 11:29:03 volumio volumio[1163]: info: Discovery: this is already registered, 33b20e60-4e68-48d5-beab-6103d46cab71
Aug 30 11:29:03 volumio volumio[1163]: info: Discovery: Found device Volumio
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:03 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:03 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:03 volumio sudo[1898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 30 11:29:03 volumio sudo[1901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 30 11:29:03 volumio sudo[1901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 30 11:29:03 volumio sudo[1902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:03 volumio sudo[1898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:04 volumio volumio[1163]: info: Volumio called home
Aug 30 11:29:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Aug 30 11:29:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Aug 30 11:29:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 30 11:29:04 volumio systemd[1]: shairport-sync.service: Consumed 1.854s CPU time.
Aug 30 11:29:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 30 11:29:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Aug 30 11:29:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Aug 30 11:29:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 30 11:29:04 volumio sudo[1901]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:04 volumio sudo[1898]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:04 volumio volumio[1163]: info: Shairport-Sync Started
Aug 30 11:29:04 volumio volumio[1163]: Error adding Membership: Error: addMembership EINVAL
Aug 30 11:29:04 volumio volumio[1163]: info: Shairport-Sync Started
Aug 30 11:29:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 30 11:29:04 volumio sudo[1902]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:04 volumio volumio[1163]: info: Shairport-Sync Started
Aug 30 11:29:04 volumio volumio[1163]: info: New Spotify access tokenBQCdl0y8vM...
Aug 30 11:29:04 volumio volumio[1163]: info: Spotify credentials grant success - running version from March 24, 2019
Aug 30 11:29:04 volumio volumio[1163]: SPOTIFY: User informations: {"account_id":"MZQM3O1ViH","country":"DZ","display_name":"Wirewalker","email":"elmecherfi.amine@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/osizwrfkj7mbog106gbgj0p8i"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/osizwrfkj7mbog106gbgj0p8i","id":"osizwrfkj7mbog106gbgj0p8i","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1042245145981108&height=300&width=300&ext=1790676960&hash=AfsX3mlz4G27qAarqWFLYiXI","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1042245145981108&height=50&width=50&ext=1790676960&hash=AftMBR0nGobO9ANSNUhncUet","width":64}],"product":"free","type":"user","uri":"spotify:user:osizwrfkj7mbog106gbgj0p8i"}
Aug 30 11:29:04 volumio volumio[1163]: info: Spotify Successfully logged in
Aug 30 11:29:04 volumio volumio[1163]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Aug 30 11:29:04 volumio volumio[1163]: info: [1788085744267] CoreMusicLibrary::Adding element Spotify
Aug 30 11:29:04 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:04 volumio volumio[1163]: Cannot find translation for source YouTube2
Aug 30 11:29:04 volumio volumio[1163]: Cannot find translation for source YouTube Music
Aug 30 11:29:04 volumio volumio[1163]: Cannot find translation for source Spotify
Aug 30 11:29:05 volumio sudo[1953]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Aug 30 11:29:05 volumio sudo[1952]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Aug 30 11:29:05 volumio sudo[1952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:05 volumio sudo[1953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:05 volumio sudo[1953]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:06 volumio sudo[1952]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:06 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.2.40 from 192.168.2.200 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Edg/152.0.0.0 Engine version: 3 Transport: polling Total Clients: 3
Aug 30 11:29:06 volumio sudo[1962]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Aug 30 11:29:06 volumio sudo[1962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:06 volumio sudo[1961]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Aug 30 11:29:06 volumio sudo[1961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:06 volumio sudo[1961]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:06 volumio sudo[1962]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:06 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.2.40 from 192.168.2.200 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Edg/152.0.0.0 Engine version: 3 Transport: polling Total Clients: 4
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:06 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Aug 30 11:29:06 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:06 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:06 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:06 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:06 volumio volumio[1163]: info: Listing playlists
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Aug 30 11:29:06 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Aug 30 11:29:06 volumio volumio[1163]: info: go-librespot daemon successfully initialized
Aug 30 11:29:06 volumio go-librespot[1888]: time="2026-08-30T11:29:06+01:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:29:06 volumio go-librespot[1888]: time="2026-08-30T11:29:06+01:00" level=debug msg="app state loaded"
Aug 30 11:29:07 volumio go-librespot[1888]: time="2026-08-30T11:29:07+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.558+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
Aug 30 11:29:07 volumio volumio[1163]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5
Aug 30 11:29:07 volumio volumio[1163]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.837+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist"
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.838+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist"
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.839+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist"
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.839+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist"
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.840+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist"
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.840+01:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled"
Aug 30 11:29:07 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:07 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:07 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.842+01:00 level=INFO msg="system info for 6d00f6f903b8eac05efb96aca885b221" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119
Aug 30 11:29:07 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:07.952+01:00 level=INFO msg="bootstrapping state" hasInternet=true
Aug 30 11:29:07 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:07 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:07 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:07 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:07 volumio volumio-remote-updater[719]: Test mode disabled
Aug 30 11:29:07 volumio volumio-remote-updater[719]: Alpha mode disabled
Aug 30 11:29:07 volumio volumio-remote-updater[719]: Alpha legacy test mode disabled
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:08 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=info msg="zeroconf server listening on port 35795"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 30 11:29:08 volumio volumio[1163]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:29:08 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:08.148+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory"
Aug 30 11:29:08 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:08.149+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory"
Aug 30 11:29:08 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:08.149+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory"
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:29:08 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:08 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:08 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Aug 30 11:29:08 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Aug 30 11:29:08 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:08.154+01:00 level=INFO msg="enabling local network discovery"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=debug msg="obtained new client token: AAEeaz5FXVpyLtlQmg/yscsuqo5NVkNbZ5vPAXU/17QC0FtlEKS29fWzOgrN/PEwUCX4+U8bx7PENHiykR7xKurLB3vavbHs6gT6ZTH0FMG7AJ2Wxp46N7orKAVVk70ZTT1Fq3Fzu01NASHvO1mZkDeTjWN3f2rxqE2jVOXoHbpaXKLArsMInUqHVB18sw0pmOeYu3jWo9VDR3Dlimvjs5jyj58Jg2H/WnX0bwrK+crx3YvWTLkGB3bb"
Aug 30 11:29:08 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5.
Aug 30 11:29:08 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:29:08 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 30 11:29:08 volumio sudo[1870]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070"
Aug 30 11:29:08 volumio volumio[1163]: info: Upmpdcli Daemon Started
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=debug msg="completed keyexchange"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=debug msg="completed challenge"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=info msg="authenticated AP" username="os*********************8i"
Aug 30 11:29:08 volumio go-librespot[1888]: time="2026-08-30T11:29:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 30 11:29:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:29:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:29:09 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:09 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:09 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:09 volumio volumio5-onboarding[1839]: time=2026-08-30T11:29:09.140+01:00 level=INFO msg="service successfully established" component=discovery/localnet
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:29:09 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:09 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:09 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:09 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Aug 30 11:29:09 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket
Aug 30 11:29:09 volumio volumio[1163]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:29:10 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Aug 30 11:29:11 volumio volumio[1163]: info: CoreCommandRouter::volumioGetQueue
Aug 30 11:29:11 volumio volumio[1163]: info: CoreStateMachine::getQueue
Aug 30 11:29:11 volumio volumio[1163]: info: CorePlayQueue::getQueue
Aug 30 11:29:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Aug 30 11:29:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:11 volumio go-librespot[1993]: go-librespot daemon starting...
Aug 30 11:29:11 volumio go-librespot[1994]: time="2026-08-30T11:29:11+01:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:29:11 volumio go-librespot[1994]: time="2026-08-30T11:29:11+01:00" level=debug msg="app state loaded"
Aug 30 11:29:12 volumio volumio[1163]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=info msg="zeroconf server listening on port 41729"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=debug msg="obtained new client token: AAHyXGQlKSMSpdjoFWvQqBERrABC4TW0XxJQI1CoTizq12TcmXsw9clzf2PzS7sVX/8b60mz+SMc7askD11i9GFIMwZlkaxiPHIgq9vdNfI3/BDfaBtJFNIOhQs7tuF4f6ZkRxTGGZXh4qVfZqzGqnHgxAZgsJVGBG+kBi5TEmSsYBNuXisKTiGumiuGhx+lyV7QY3CKZ2cFPMyt16gnEi7lOw1qxJs6OtQdlnIteKPpmONCagzk1VX9"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=debug msg="completed keyexchange"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=debug msg="completed challenge"
Aug 30 11:29:12 volumio go-librespot[1994]: time="2026-08-30T11:29:12+01:00" level=info msg="authenticated AP" username="os*********************8i"
Aug 30 11:29:13 volumio go-librespot[1994]: time="2026-08-30T11:29:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 30 11:29:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:29:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:29:13 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket
Aug 30 11:29:13 volumio volumio[1163]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:29:13 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 30 11:29:13 volumio volumio[1163]: info: CURURI: music-library
Aug 30 11:29:13 volumio volumio[1163]: error: Failed to execute browseSource, failure: TypeError: Cannot read properties of undefined (reading 'then')
Aug 30 11:29:14 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Aug 30 11:29:14 volumio volumio[1163]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:15 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Aug 30 11:29:15 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:15 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:15 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:15 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:15 volumio volumio[1163]: info: Listing playlists
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:29:15 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:15 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:15 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:15 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:15 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:16 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Aug 30 11:29:16 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket
Aug 30 11:29:16 volumio volumio[1163]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:29:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Aug 30 11:29:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:16 volumio go-librespot[2030]: go-librespot daemon starting...
Aug 30 11:29:16 volumio go-librespot[2031]: time="2026-08-30T11:29:16+01:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:29:16 volumio go-librespot[2031]: time="2026-08-30T11:29:16+01:00" level=debug msg="app state loaded"
Aug 30 11:29:16 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Aug 30 11:29:16 volumio go-librespot[2031]: time="2026-08-30T11:29:16+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:29:16 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=info msg="zeroconf server listening on port 45877"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=debug msg="obtained new client token: AAHVk/lTZdMvKTGYzze2hpJtKnYl6mvAjkaJ1DTTfBMKESUTER4mVXfBTw6bv7PQd52sEjh+6A0cz4sEFcGeurQ3xV2HMWZ59PLGSEIl4pmryDdXgEr9L2gqMUY1UnMzmrobaWcPpw9FYjQ4jYoySyD1lz48YbXugjtldKqZIAFD75qQpOS38Nx2hIKI+nMpZGblALBTJ+/k0m3g+JlB3dVy3xs9BFH2bw/vpOjMF/CGIMzJlBhR73Sx"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=debug msg="completed keyexchange"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=debug msg="completed challenge"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=info msg="authenticated AP" username="os*********************8i"
Aug 30 11:29:17 volumio go-librespot[2031]: time="2026-08-30T11:29:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 30 11:29:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:29:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:29:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:29:17 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:17 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:17 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:17 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Aug 30 11:29:18 volumio mpd[1863]: 2026-08-30T11:29:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Aug 30 11:29:18 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Aug 30 11:29:18 volumio sudo[1819]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:18 volumio sudo[1832]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:18 volumio volumio[1163]: info: Completed starting Core Plugins
Aug 30 11:29:18 volumio volumio[1163]: info: -------------------------------------------
Aug 30 11:29:18 volumio volumio[1163]: info: ----- MyVolumio plugins startup ----
Aug 30 11:29:18 volumio volumio[1163]: info: -------------------------------------------
Aug 30 11:29:18 volumio volumio[1163]: info: [MyVolumio PluginManager] Fetching plans data....
Aug 30 11:29:18 volumio volumio[1163]: error: MPD error: The expression evaluated to a falsy value:
Aug 30 11:29:18 volumio volumio[1163]: assert.ok(self.idling)
Aug 30 11:29:18 volumio volumio[1163]: error: The expression evaluated to a falsy value:
Aug 30 11:29:18 volumio volumio[1163]: assert.ok(self.idling)
Aug 30 11:29:18 volumio volumio[1163]: info: MPD running with PID1863
Aug 30 11:29:18 volumio volumio[1163]: ,establishing connection
Aug 30 11:29:18 volumio volumio[1163]: error: MPD error: The expression evaluated to a falsy value:
Aug 30 11:29:18 volumio volumio[1163]: assert.ok(self.idling)
Aug 30 11:29:18 volumio volumio[1163]: error: The expression evaluated to a falsy value:
Aug 30 11:29:18 volumio volumio[1163]: assert.ok(self.idling)
Aug 30 11:29:18 volumio volumio[1163]: error: updateQueue error: null
Aug 30 11:29:19 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket
Aug 30 11:29:19 volumio volumio[1163]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:29:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Aug 30 11:29:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:20 volumio go-librespot[2054]: go-librespot daemon starting...
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=debug msg="app state loaded"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=info msg="zeroconf server listening on port 46491"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=debug msg="obtained new client token: AAEvCJOFOM2EEcHYTVe+F3eqrmjYnkULKUU3bAYy+wBG+sRQIv+07kvVzBH4REbMXDmLewTjrICvl2cZlCzy1v0Jw0/ooR2rUvwSmspMmzWNrnNFqonYUFho1tTXfp+fLEQ7N0s3K4rIdtngxQzrW/dGsA/K7/z41oIcA/gZtpMh6/uXlQsuPYJ+bfDft+kEegEW9mzbey08xfWaSFrbp6HGmc4P6pguys7YawVuZkoRDIeEZ6HlJg=="
Aug 30 11:29:20 volumio go-librespot[2055]: time="2026-08-30T11:29:20+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused"
Aug 30 11:29:20 volumio upmpdcli[2063]: writing RSA key
Aug 30 11:29:21 volumio go-librespot[2055]: time="2026-08-30T11:29:21+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused"
Aug 30 11:29:21 volumio go-librespot[2055]: time="2026-08-30T11:29:21+01:00" level=debug msg="connected to ap-gew1.spotify.com:80"
Aug 30 11:29:21 volumio go-librespot[2055]: time="2026-08-30T11:29:21+01:00" level=debug msg="completed keyexchange"
Aug 30 11:29:21 volumio go-librespot[2055]: time="2026-08-30T11:29:21+01:00" level=debug msg="completed challenge"
Aug 30 11:29:21 volumio go-librespot[2055]: time="2026-08-30T11:29:21+01:00" level=info msg="authenticated AP" username="os*********************8i"
Aug 30 11:29:21 volumio go-librespot[2055]: time="2026-08-30T11:29:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 30 11:29:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:29:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:29:22 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket
Aug 30 11:29:22 volumio volumio[1163]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:29:23 volumio volumio[1163]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Aug 30 11:29:24 volumio volumio[1163]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Aug 30 11:29:24 volumio volumio[1163]: info: Received Get System Version
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 30 11:29:24 volumio volumio[1163]: info: Received Get System Info
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 30 11:29:24 volumio volumio[1163]: info: Discovery: Getting this device information
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState
Aug 30 11:29:24 volumio volumio[1163]: info: CorePlayQueue::getTrack 0
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Aug 30 11:29:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Aug 30 11:29:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:24 volumio go-librespot[2104]: go-librespot daemon starting...
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=debug msg="app state loaded"
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=info msg="zeroconf server listening on port 41935"
Aug 30 11:29:24 volumio go-librespot[2105]: time="2026-08-30T11:29:24+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 30 11:29:24 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 30 11:29:24 volumio volumio[1163]: info: CURURI: music-library
Aug 30 11:29:25 volumio volumio[1163]: info: Preload queue cleared
Aug 30 11:29:25 volumio go-librespot[2105]: time="2026-08-30T11:29:25+01:00" level=debug msg="obtained new client token: AAF09qYe9Ia0pSEB6/PokFkTMAU5HfVWrykT0CQrGYJci7vqmRqk4om3+n67WWVPBou3po1UvhriaCClGqTGjr61/gnuxdTxEl+cKXx+9ZjAk1MXjM0czgxwnJ5c9nPbXur0FvOH+p0AAMCXoCFzgUlPaRIsni6Ob3O9/jT5OMzq/2QcvG5aEtajR0hLF+taYOYdAow3CuGMKDT7AybpOC2mhJ4LA4bLjZJGskcyJttrUV+sSnx2A7/c"
Aug 30 11:29:25 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket
Aug 30 11:29:25 volumio go-librespot[2105]: time="2026-08-30T11:29:25+01:00" level=debug msg="new websocket client"
Aug 30 11:29:25 volumio volumio[1163]: info: Connection to go-librespot Websocket established
Aug 30 11:29:25 volumio go-librespot[2105]: time="2026-08-30T11:29:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070"
Aug 30 11:29:25 volumio go-librespot[2105]: time="2026-08-30T11:29:25+01:00" level=debug msg="completed keyexchange"
Aug 30 11:29:25 volumio go-librespot[2105]: time="2026-08-30T11:29:25+01:00" level=debug msg="completed challenge"
Aug 30 11:29:25 volumio go-librespot[2105]: time="2026-08-30T11:29:25+01:00" level=info msg="authenticated AP" username="os*********************8i"
Aug 30 11:29:25 volumio go-librespot[2105]: time="2026-08-30T11:29:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Aug 30 11:29:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:29:25 volumio volumio[1163]: info: Connection to go-librespot Websocket closed
Aug 30 11:29:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:29:25 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 30 11:29:25 volumio volumio[1163]: info: CURURI: music-library/NAS
Aug 30 11:29:26 volumio volumio[1163]: info: Preload queue cleared
Aug 30 11:29:26 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 30 11:29:26 volumio volumio[1163]: info: CURURI: music-library/NAS/MUSIC
Aug 30 11:29:26 volumio volumio[1163]: info: Preload queue cleared
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Aug 30 11:29:26 volumio volumio[1163]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Aug 30 11:29:26 volumio volumio[1163]: info: Adding plugin bluetooth to MyMusic Plugins
Aug 30 11:29:27 volumio volumio[1163]: info: Adding plugin multiroom to MyMusic Plugins
Aug 30 11:29:27 volumio volumio[1163]: info: Adding plugin metavolumio to MyMusic Plugins
Aug 30 11:29:27 volumio volumio[1163]: info: Adding plugin cd_controller to MyMusic Plugins
Aug 30 11:29:27 volumio volumio[1163]: info: Adding plugin qobuzconnect to MyMusic Plugins
Aug 30 11:29:27 volumio volumio[1163]: info: Adding plugin smart_inputs to MyMusic Plugins
Aug 30 11:29:27 volumio volumio[1163]: info: Adding plugin tidalconnect to MyMusic Plugins
Aug 30 11:29:27 volumio volumio[1163]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Aug 30 11:29:27 volumio volumio[1163]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Aug 30 11:29:27 volumio volumio[1163]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Aug 30 11:29:27 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:27 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:29:27 volumio volumio[1163]: info: Starting MyVolumio Remote Streaming Endpoints
Aug 30 11:29:27 volumio volumio[1163]: info: MyVolumio login type: Token
Aug 30 11:29:27 volumio volumio[1163]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Aug 30 11:29:27 volumio volumio[1163]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Aug 30 11:29:28 volumio volumio[1163]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Aug 30 11:29:28 volumio volumio[1163]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Aug 30 11:29:28 volumio volumio[1163]: info: Streaming services startup
Aug 30 11:29:28 volumio volumio[1163]: info: Starting Streaming Daemon
Aug 30 11:29:28 volumio sudo[2118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Aug 30 11:29:28 volumio sudo[2118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 30 11:29:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Aug 30 11:29:28 volumio volumio[1163]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Aug 30 11:29:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Aug 30 11:29:28 volumio go-librespot[2124]: go-librespot daemon starting...
Aug 30 11:29:28 volumio sudo[2118]: pam_unix(sudo:session): session closed for user root
Aug 30 11:29:28 volumio volumio[1163]: info: Getting Spotify volume
Aug 30 11:29:28 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=debug msg="app state loaded"
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:29:28 volumio volumio[1163]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 30 11:29:28 volumio volumio[1163]: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:29:28 volumio volumio[1163]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Aug 30 11:29:28 volumio volumio[1163]: errno: -111,
Aug 30 11:29:28 volumio volumio[1163]: code: 'ECONNREFUSED',
Aug 30 11:29:28 volumio volumio[1163]: syscall: 'connect',
Aug 30 11:29:28 volumio volumio[1163]: address: '127.0.0.1',
Aug 30 11:29:28 volumio volumio[1163]: port: 9879,
Aug 30 11:29:28 volumio volumio[1163]: response: undefined
Aug 30 11:29:28 volumio volumio[1163]: }
Aug 30 11:29:28 volumio volumio[1163]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=info msg="zeroconf server listening on port 39181"
Aug 30 11:29:28 volumio go-librespot[2125]: time="2026-08-30T11:29:28+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Aug 30 11:29:28 volumio sudo[2147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 11:28'
Aug 30 11:29:28 volumio sudo[2147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026"
VOLUMIO_VERSION="4.119"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"