-- Logs begin at Fri 2025-05-09 15:32:50 UTC, end at Fri 2025-05-09 15:34:00 UTC. -- May 09 15:33:00 volumio kernel: [drm:cdv_intel_dp_complete_link_train [gma500_gfx]] *ERROR* failed to train DP, aborting May 09 15:33:00 volumio firststart.sh[843]: Creating /var/log/samba/cores folder May 09 15:33:00 volumio firststart.sh[843]: Removing default SSH host keys May 09 15:33:00 volumio firststart.sh[843]: removed '/etc/ssh/ssh_host_ecdsa_key' May 09 15:33:00 volumio firststart.sh[843]: removed '/etc/ssh/ssh_host_ecdsa_key.pub' May 09 15:33:00 volumio firststart.sh[843]: removed '/etc/ssh/ssh_host_ed25519_key' May 09 15:33:00 volumio firststart.sh[843]: removed '/etc/ssh/ssh_host_ed25519_key.pub' May 09 15:33:00 volumio firststart.sh[843]: removed '/etc/ssh/ssh_host_rsa_key' May 09 15:33:00 volumio firststart.sh[843]: removed '/etc/ssh/ssh_host_rsa_key.pub' May 09 15:33:00 volumio firststart.sh[843]: Generating SSH host keys May 09 15:33:00 volumio systemd[1]: Received SIGRTMIN+21 from PID 354 (plymouthd). May 09 15:33:00 volumio loadcpufreq[770]: Loading cpufreq kernel modules...error: unexpectedly disconnected from boot status daemon May 09 15:33:00 volumio systemd[1]: plymouth-quit.service: Succeeded. May 09 15:33:00 volumio systemd[1]: Started Terminate Plymouth Boot Screen. May 09 15:33:00 volumio systemd[1]: plymouth-quit-wait.service: Succeeded. May 09 15:33:00 volumio systemd[1]: Started Hold until boot process finishes up. May 09 15:33:00 volumio systemd[1]: Started Getty on tty1. May 09 15:33:00 volumio systemd[1]: Reached target Login Prompts. May 09 15:33:00 volumio ifplugd(eth0)[924]: ifplugd 0.28 initializing. May 09 15:33:00 volumio ifplugd(eth0)[924]: Using interface eth0/00:22:4D:AC:04:7B with driver (version: 6.6.32-volumio) May 09 15:33:00 volumio ifplugd(eth0)[924]: Using detection mode: SIOCETHTOOL May 09 15:33:00 volumio ifplugd(eth0)[924]: Initialization complete, link beat not detected. May 09 15:33:00 volumio ifplugd[798]: Network Interface Plugging Daemon...start eth0...done. May 09 15:33:00 volumio systemd[1]: Started LSB: Brings up/down network automatically. May 09 15:33:00 volumio ntpd[822]: error resolving pool 2.debian.pool.ntp.org: System error (-11) May 09 15:33:00 volumio loadcpufreq[770]: done (acpi-cpufreq). May 09 15:33:00 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. May 09 15:33:00 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... May 09 15:33:00 volumio cpufrequtils[964]: CPUFreq Utilities: Setting ondemand CPUFreq governor...disabled, governor not available...done. May 09 15:33:00 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. May 09 15:33:00 volumio startx[841]: X.Org X Server 1.20.4 May 09 15:33:00 volumio startx[841]: X Protocol Version 11, Revision 0 May 09 15:33:00 volumio startx[841]: Build Operating System: Linux 5.10.0-10-amd64 x86_64 Debian May 09 15:33:00 volumio startx[841]: Current Operating System: Linux volumio 6.6.32-volumio #2 SMP PREEMPT_DYNAMIC Wed May 29 23:04:42 CEST 2024 x86_64 May 09 15:33:00 volumio startx[841]: Kernel command line: BOOT_IMAGE=/vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 biosdevname=0 imgpart=UUID=dbd79e5a-e987-4a82-a3e6-79378c35f030 bootpart=UUID=BD4C-8AAA datapart=UUID=9bd88860-d6ee-4151-96d8-1c7f28861b65 hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=vendor net.ifnames=0 use_kmsg=no May 09 15:33:00 volumio startx[841]: Build Date: 18 December 2021 09:05:36AM May 09 15:33:00 volumio startx[841]: xorg-server 2:1.20.4-1+deb10u4 (https://www.debian.org/support) May 09 15:33:00 volumio startx[841]: Current version of pixman: 0.36.0 May 09 15:33:00 volumio startx[841]: Before reporting problems, check http://wiki.x.org May 09 15:33:00 volumio startx[841]: to make sure that you have the latest version. May 09 15:33:00 volumio startx[841]: Markers: (--) probed, (**) from config file, (==) default setting, May 09 15:33:00 volumio startx[841]: (++) from command line, (!!) notice, (II) informational, May 09 15:33:00 volumio startx[841]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. May 09 15:33:00 volumio startx[841]: (==) Log file: "/var/log/Xorg.0.log", Time: Fri May 9 15:33:00 2025 May 09 15:33:00 volumio startx[841]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" May 09 15:33:01 volumio startx[841]: pci id for fd 14: 8086:0be2, driver (null) May 09 15:33:01 volumio ntpd[822]: error resolving pool 3.debian.pool.ntp.org: System error (-11) May 09 15:33:01 volumio systemd[1]: soundcard-init.service: Succeeded. May 09 15:33:01 volumio volumio-remote-updater[665]: [2025-05-09 15:33:01] [info] asio async_connect error: system:111 (Connection refused) May 09 15:33:01 volumio volumio-remote-updater[665]: [2025-05-09 15:33:01] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) May 09 15:33:01 volumio volumio-remote-updater[665]: [2025-05-09 15:33:01] [error] handle_connect error: Underlying Transport Error May 09 15:33:01 volumio volumio-time-update[656]: volumio-time-update-util: Fetching time from Volumio... May 09 15:33:02 volumio volumio-time-update[656]: volumio-time-update-util: Date not found in response May 09 15:33:02 volumio volumio-time-update[656]: volumio-time-update-util: Retrying in 5 seconds... May 09 15:33:03 volumio firststart.sh[843]: debconf: unable to initialize frontend: Dialog May 09 15:33:03 volumio firststart.sh[843]: debconf: (TERM is not set, so the dialog frontend is not usable.) May 09 15:33:03 volumio firststart.sh[843]: debconf: falling back to frontend: Readline May 09 15:33:03 volumio firststart.sh[843]: debconf: unable to initialize frontend: Readline May 09 15:33:03 volumio firststart.sh[843]: debconf: (This frontend requires a controlling tty.) May 09 15:33:03 volumio firststart.sh[843]: debconf: falling back to frontend: Teletype May 09 15:33:04 volumio startx[841]: (II) modeset(0): Initializing kms color map for depth 24, 8 bpc. May 09 15:33:05 volumio mpd[827]: May 09 15:33 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 09 15:33:05 volumio mpd[827]: May 09 15:33 : exception: Database corrupted May 09 15:33:05 volumio systemd[1]: Started Music Player Daemon. May 09 15:33:05 volumio mpd_monitor.sh[663]: MPD Monitor Service: MPD restarted due to no mpc output. May 09 15:33:06 volumio volumio[840]: info: ------------------------------------------- May 09 15:33:06 volumio volumio[840]: info: ----- Volumio3 ---- May 09 15:33:06 volumio volumio[840]: info: ------------------------------------------- May 09 15:33:06 volumio volumio[840]: info: ----- System startup ---- May 09 15:33:06 volumio volumio[840]: info: ------------------------------------------- May 09 15:33:06 volumio firststart.sh[843]: Creating SSH2 RSA key; this may take some time ... May 09 15:33:06 volumio firststart.sh[843]: 2048 SHA256:IHRQcd8GTI53u8gs6Knueh+ZNPygy5Yxdk45jQOsoYE root@volumio (RSA) May 09 15:33:07 volumio volumio-time-update[656]: volumio-time-update-util: Fetching time from Volumio... May 09 15:33:07 volumio volumio-time-update[656]: volumio-time-update-util: Date not found in response May 09 15:33:07 volumio volumio-time-update[656]: volumio-time-update-util: Retrying in 5 seconds... May 09 15:33:07 volumio volumio[840]: info: File /data/configuration/plugins.json does not exist. Copying from Volumio May 09 15:33:07 volumio volumio[840]: info: MYVOLUMIO Environment detected May 09 15:33:07 volumio firststart.sh[843]: Creating SSH2 DSA key; this may take some time ... May 09 15:33:07 volumio firststart.sh[843]: 1024 SHA256:EPMmhc55iHHcxeVYZKLU8CBmKW4X0hdpCf0/mSqeI5U root@volumio (DSA) May 09 15:33:07 volumio firststart.sh[843]: Creating SSH2 ECDSA key; this may take some time ... May 09 15:33:07 volumio firststart.sh[843]: 256 SHA256:9ngar94wCQ5+ShOStUoNY1I9/eO3Tfm7AY0Ee6wuwek root@volumio (ECDSA) May 09 15:33:07 volumio volumio[840]: info: Plugin folders cleanup May 09 15:33:07 volumio volumio[840]: info: Scanning into folder /volumio/app/plugins/ May 09 15:33:07 volumio volumio[840]: info: Scanning category audio_interface May 09 15:33:07 volumio volumio[840]: info: Scanning category miscellanea May 09 15:33:07 volumio volumio[840]: info: Scanning category music_service May 09 15:33:07 volumio volumio[840]: info: Scanning category plugins.json May 09 15:33:07 volumio volumio[840]: info: Scanning category system_controller May 09 15:33:07 volumio volumio[840]: info: Scanning category user_interface May 09 15:33:07 volumio volumio[840]: info: Scanning into folder /data/plugins/ May 09 15:33:07 volumio volumio[840]: info: Plugin folders cleanup completed May 09 15:33:07 volumio volumio[840]: info: ------------------------------------------- May 09 15:33:07 volumio volumio[840]: info: ----- Core plugins startup ---- May 09 15:33:07 volumio volumio[840]: info: ------------------------------------------- May 09 15:33:07 volumio volumio[840]: info: Loading plugins from folder /volumio/app/plugins/ May 09 15:33:07 volumio volumio[840]: info: Adding plugin upnp to MyMusic Plugins May 09 15:33:07 volumio volumio[840]: info: Adding plugin airplay_emulation to MyMusic Plugins May 09 15:33:07 volumio volumio[840]: info: Adding plugin upnp_browser to MyMusic Plugins May 09 15:33:07 volumio volumio[840]: info: Loading plugins from folder /data/plugins/ May 09 15:33:07 volumio volumio[840]: info: Loading plugin "system"... May 09 15:33:07 volumio volumio[840]: info: No id defined. Creating one May 09 15:33:07 volumio volumio[840]: info: Loading plugin "appearance"... May 09 15:33:08 volumio kernel: e1000e 0000:01:00.0 eth0: NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx May 09 15:33:08 volumio sh[630]: eth0: carrier acquired May 09 15:33:08 volumio dhcpcd[764]: eth0: carrier acquired May 09 15:33:08 volumio dhcpcd[705]: eth0: carrier acquired May 09 15:33:08 volumio sh[630]: DUID 00:04:b2:02:dd:06:67:2f:e3:11:bf:cf:00:11:11:6c:b2:51 May 09 15:33:08 volumio sh[630]: eth0: IAID 4d:ac:04:7b May 09 15:33:08 volumio sh[630]: eth0: adding address fe80::c3d1:c38e:b9e4:f03c May 09 15:33:08 volumio sh[630]: ipv6_addaddr1: Permission denied May 09 15:33:08 volumio dhcpcd[705]: DUID 00:04:b2:02:dd:06:67:2f:e3:11:bf:cf:00:11:11:6c:b2:51 May 09 15:33:08 volumio dhcpcd[705]: eth0: IAID 4d:ac:04:7b May 09 15:33:08 volumio dhcpcd[705]: eth0: adding address fe80::c3d1:c38e:b9e4:f03c May 09 15:33:08 volumio dhcpcd[705]: ipv6_addaddr1: Permission denied May 09 15:33:08 volumio dhcpcd[764]: DUID 00:04:b2:02:dd:06:67:2f:e3:11:bf:cf:00:11:11:6c:b2:51 May 09 15:33:08 volumio dhcpcd[764]: eth0: IAID 4d:ac:04:7b May 09 15:33:08 volumio dhcpcd[764]: eth0: adding address fe80::c3d1:c38e:b9e4:f03c May 09 15:33:08 volumio dhcpcd[764]: ipv6_addaddr1: Permission denied May 09 15:33:08 volumio kernel: [drm:cdv_intel_dp_complete_link_train [gma500_gfx]] *ERROR* failed to train DP, aborting May 09 15:33:09 volumio sh[630]: eth0: soliciting an IPv6 router May 09 15:33:09 volumio dhcpcd[705]: eth0: soliciting an IPv6 router May 09 15:33:09 volumio dhcpcd[764]: eth0: soliciting a DHCP lease May 09 15:33:09 volumio dhcpcd[764]: eth0: offered 192.168.0.201 from 192.168.0.1 May 09 15:33:09 volumio dhcpcd[764]: eth0: probing address 192.168.0.201/24 May 09 15:33:09 volumio dhcpcd[764]: eth0: soliciting an IPv6 router May 09 15:33:09 volumio sh[630]: eth0: soliciting a DHCP lease May 09 15:33:09 volumio dhcpcd[705]: eth0: soliciting a DHCP lease May 09 15:33:09 volumio sh[630]: eth0: offered 192.168.0.201 from 192.168.0.1 May 09 15:33:09 volumio dhcpcd[705]: eth0: offered 192.168.0.201 from 192.168.0.1 May 09 15:33:09 volumio sh[630]: eth0: probing address 192.168.0.201/24 May 09 15:33:09 volumio dhcpcd[705]: eth0: probing address 192.168.0.201/24 May 09 15:33:09 volumio volumio-remote-updater[665]: [2025-05-09 15:33:09] [connect] Successful connection May 09 15:33:09 volumio ifplugd(eth0)[924]: Link beat detected. May 09 15:33:09 volumio systemd[1]: Reloading. May 09 15:33:09 volumio ifplugd(eth0)[924]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. May 09 15:33:09 volumio ifplugd(eth0)[924]: client: ifup: waiting for lock on /run/network/ifstate.eth0 May 09 15:33:10 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 09 15:33:10 volumio volumio[840]: info: Loading plugin "network"... May 09 15:33:10 volumio volumio[840]: info: Refreshing Cached IP Addresses May 09 15:33:10 volumio sudo[1247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 09 15:33:10 volumio sudo[1247]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:10 volumio sudo[1247]: pam_unix(sudo:session): session closed for user root May 09 15:33:10 volumio sudo[1249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 09 15:33:10 volumio sudo[1249]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:10 volumio volumio[840]: info: Loading plugin "services"... May 09 15:33:10 volumio volumio[840]: info: Loading plugin "alsa_controller"... May 09 15:33:10 volumio sudo[1249]: pam_unix(sudo:session): session closed for user root May 09 15:33:10 volumio sudo[1259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 09 15:33:10 volumio sudo[1259]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:10 volumio sudo[1259]: pam_unix(sudo:session): session closed for user root May 09 15:33:10 volumio volumio[840]: warn: The ALSA output card is not set, defaulting to card [object Object] May 09 15:33:10 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 09 15:33:10 volumio volumio[840]: info: Found match in Cards Database: setting mixer for card Analog Out May 09 15:33:10 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 09 15:33:10 volumio systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 09 15:33:10 volumio volumio[840]: info: Setting mixer Master for card Analog Out May 09 15:33:10 volumio volumio[840]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 09 15:33:10 volumio volumio[840]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 09 15:33:10 volumio volumio[840]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 09 15:33:10 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 15:33:10 volumio volumio[840]: info: Loading plugin "wizard"... May 09 15:33:10 volumio volumio[840]: info: Loading plugin "networkfs"... May 09 15:33:10 volumio firststart.sh[843]: rescue-ssh.target is a disabled or a static unit, not starting it. May 09 15:33:10 volumio volumio[840]: info: Starting Udev Watcher for removable devices May 09 15:33:11 volumio volumio[840]: info: Mounting Device EFI May 09 15:33:11 volumio sudo[1312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/EFI -o noatime,dmask=0000,fmask=0000,iocharset=utf8 May 09 15:33:11 volumio sudo[1312]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:11 volumio firststart.sh[843]: insserv: warning: current start runlevel(s) (empty) of script `ssh' overrides LSB defaults (2 3 4 5). May 09 15:33:11 volumio firststart.sh[843]: insserv: warning: current stop runlevel(s) (2 3 4 5) of script `ssh' overrides LSB defaults (empty). May 09 15:33:11 volumio kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! May 09 15:33:11 volumio kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. May 09 15:33:11 volumio sudo[1312]: pam_unix(sudo:session): session closed for user root May 09 15:33:11 volumio volumio[840]: info: Mounting Device ihdd May 09 15:33:11 volumio systemd[1]: Reloading. May 09 15:33:11 volumio sudo[1319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/INTERNAL/ -o noatime May 09 15:33:11 volumio sudo[1319]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:11 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 09 15:33:11 volumio mount.exfat[1333]: volume was not unmounted cleanly May 09 15:33:11 volumio sudo[1319]: pam_unix(sudo:session): session closed for user root May 09 15:33:11 volumio volumio[840]: WARN: volume was not unmounted cleanly. May 09 15:33:11 volumio volumio[840]: info: Binding Internal Memory position May 09 15:33:11 volumio sudo[1338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -o bind /mnt/INTERNAL /data/INTERNAL May 09 15:33:11 volumio sudo[1338]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:11 volumio sudo[1338]: pam_unix(sudo:session): session closed for user root May 09 15:33:11 volumio volumio[840]: info: Ignoring mount for partition: boot May 09 15:33:11 volumio volumio[840]: info: Ignoring mount for partition: volumio May 09 15:33:11 volumio volumio[840]: info: Ignoring mount for partition: volumio_data May 09 15:33:11 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 09 15:33:11 volumio volumio[840]: info: Loading plugin "volumio_command_line_client"... May 09 15:33:11 volumio volumio[840]: info: Loading plugin "upnp"... May 09 15:33:11 volumio volumio[840]: info: [1746804791702] Starting Upmpd Daemon May 09 15:33:11 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 09 15:33:11 volumio volumio[840]: info: Loading plugin "my_music"... May 09 15:33:11 volumio volumio[840]: info: Loading plugin "mpd"... May 09 15:33:12 volumio volumio-time-update[656]: volumio-time-update-util: Fetching time from Volumio... May 09 15:33:12 volumio volumio-time-update[656]: volumio-time-update-util: Date not found in response May 09 15:33:12 volumio volumio-time-update[656]: volumio-time-update-util: Retrying in 5 seconds... May 09 15:33:12 volumio volumio[840]: info: Loading plugin "upnp_browser"... May 09 15:33:12 volumio firststart.sh[843]: Enabling SSH for first boot May 09 15:33:12 volumio systemd[1]: Starting OpenBSD Secure Shell server... May 09 15:33:12 volumio sshd[1355]: Server listening on 0.0.0.0 port 22. May 09 15:33:12 volumio sshd[1355]: Server listening on :: port 22. May 09 15:33:12 volumio systemd[1]: Started OpenBSD Secure Shell server. May 09 15:33:12 volumio firststart.sh[843]: Disabling firststart service May 09 15:33:12 volumio firststart.sh[843]: Removed /etc/systemd/system/multi-user.target.wants/firststart.service. May 09 15:33:12 volumio systemd[1]: Reloading. May 09 15:33:12 volumio volumio[840]: info: Loading plugin "alarm-clock"... May 09 15:33:13 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 09 15:33:13 volumio volumio[840]: info: Loading plugin "airplay_emulation"... May 09 15:33:13 volumio volumio[840]: info: Starting Shairport Sync May 09 15:33:13 volumio volumio[840]: info: Loading plugin "last_100"... May 09 15:33:13 volumio volumio[840]: info: Loading plugin "webradio"... May 09 15:33:13 volumio volumio[840]: info: Loading plugin "i2s_dacs"... May 09 15:33:13 volumio volumio[840]: info: I2S DAC not set, start Auto-detection May 09 15:33:13 volumio volumio[840]: info: Loading plugin "volumiodiscovery"... May 09 15:33:13 volumio volumio[840]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 09 15:33:13 volumio volumio[840]: *** WARNING *** Please fix your application to use the native API of Avahi! May 09 15:33:13 volumio node[840]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 09 15:33:13 volumio volumio[840]: *** WARNING *** For more information see May 09 15:33:13 volumio volumio[840]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 09 15:33:13 volumio volumio[840]: *** WARNING *** Please fix your application to use the native API of Avahi! May 09 15:33:13 volumio volumio[840]: *** WARNING *** For more information see May 09 15:33:13 volumio node[840]: *** WARNING *** Please fix your application to use the native API of Avahi! May 09 15:33:13 volumio node[840]: *** WARNING *** For more information see May 09 15:33:13 volumio node[840]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 09 15:33:13 volumio node[840]: *** WARNING *** Please fix your application to use the native API of Avahi! May 09 15:33:13 volumio node[840]: *** WARNING *** For more information see May 09 15:33:13 volumio volumio[840]: info: Discovery: Started advertising with name: Volumio May 09 15:33:13 volumio firststart.sh[843]: Finalizing May 09 15:33:13 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 09 15:33:13 volumio volumio[840]: info: Loading plugin "outputs"... May 09 15:33:13 volumio volumio[840]: info: Loading plugin "albumart"... May 09 15:33:13 volumio dhcpcd[764]: eth0: leased 192.168.0.201 for 86400 seconds May 09 15:33:13 volumio avahi-daemon[688]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.201. May 09 15:33:13 volumio dhcpcd[764]: eth0: adding route to 192.168.0.0/24 May 09 15:33:13 volumio dhcpcd[764]: eth0: adding default route via 192.168.0.1 May 09 15:33:13 volumio avahi-daemon[688]: New relevant interface eth0.IPv4 for mDNS. May 09 15:33:13 volumio avahi-daemon[688]: Registering new address record for 192.168.0.201 on eth0.IPv4. May 09 15:33:13 volumio volumio[840]: info: Plugin example_plugin is not enabled May 09 15:33:13 volumio volumio[840]: info: Loading plugin "inputs"... May 09 15:33:13 volumio volumio[840]: info: Loading plugin "updater_comm"... May 09 15:33:14 volumio systemd[1]: firststart.service: Succeeded. May 09 15:33:14 volumio nmbd[807]: [2025/05/09 15:33:14.017547, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 09 15:33:14 volumio nmbd[807]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 09 15:33:14 volumio systemd[1]: Started Samba NMB Daemon. May 09 15:33:14 volumio nmbd[807]: [2025/05/09 15:33:14.046624, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 09 15:33:14 volumio nmbd[807]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.201 for name WORKGROUP<1d>. May 09 15:33:14 volumio nmbd[807]: This response was from IP 192.168.0.82, reporting an IP address of 192.168.0.82. May 09 15:33:14 volumio systemd[1]: Starting Samba Winbind Daemon... May 09 15:33:14 volumio volumio[840]: Forking 3 albumart workers May 09 15:33:14 volumio ntpd[822]: ntpd exiting on signal 15 (Terminated) May 09 15:33:14 volumio systemd[1]: Stopping Network Time Service... May 09 15:33:14 volumio systemd[1]: ntp.service: Succeeded. May 09 15:33:14 volumio systemd[1]: Stopped Network Time Service. May 09 15:33:14 volumio systemd[1]: Starting Network Time Service... May 09 15:33:14 volumio ntpd[1417]: ntpd 4.2.8p12@1.3728-o (1): Starting May 09 15:33:14 volumio ntpd[1417]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 May 09 15:33:14 volumio systemd[1]: Started Network Time Service. May 09 15:33:14 volumio ntpd[1437]: proto: precision = 0.375 usec (-21) May 09 15:33:14 volumio ntpd[1437]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 09 15:33:14 volumio ntpd[1437]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 09 15:33:14 volumio ntpd[1437]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 864 days ago May 09 15:33:14 volumio ntpd[1437]: Listen and drop on 0 v6wildcard [::]:123 May 09 15:33:14 volumio ntpd[1437]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 09 15:33:14 volumio ntpd[1437]: Listen normally on 2 lo 127.0.0.1:123 May 09 15:33:14 volumio ntpd[1437]: Listen normally on 3 eth0 192.168.0.201:123 May 09 15:33:14 volumio ntpd[1437]: Listening on routing socket on fd #20 for interface updates May 09 15:33:14 volumio ntpd[1437]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 09 15:33:14 volumio ntpd[1437]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 09 15:33:14 volumio sh[630]: eth0: leased 192.168.0.201 for 86400 seconds May 09 15:33:14 volumio sh[630]: eth0: adding route to 192.168.0.0/24 May 09 15:33:14 volumio sh[630]: eth0: adding default route via 192.168.0.1 May 09 15:33:14 volumio dhcpcd[705]: eth0: leased 192.168.0.201 for 86400 seconds May 09 15:33:14 volumio dhcpcd[705]: eth0: adding route to 192.168.0.0/24 May 09 15:33:14 volumio dhcpcd[705]: eth0: adding default route via 192.168.0.1 May 09 15:33:14 volumio winbindd[1411]: [2025/05/09 15:33:14.698576, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 09 15:33:14 volumio winbindd[1411]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 09 15:33:14 volumio ntpd[1437]: ntpd exiting on signal 15 (Terminated) May 09 15:33:14 volumio systemd[1]: Stopping Network Time Service... May 09 15:33:14 volumio systemd[1]: ntp.service: Succeeded. May 09 15:33:14 volumio systemd[1]: Stopped Network Time Service. May 09 15:33:14 volumio volumio[840]: info: Plugin mpdemulation is not enabled May 09 15:33:14 volumio volumio[840]: info: Loading plugin "rest_api"... May 09 15:33:14 volumio systemd[1]: Starting Network Time Service... May 09 15:33:14 volumio volumio[840]: info: Loading plugin "websocket"... May 09 15:33:14 volumio volumio[840]: info: Starting Socket.io Server version 2.3.0 May 09 15:33:14 volumio ntpd[1479]: ntpd 4.2.8p12@1.3728-o (1): Starting May 09 15:33:14 volumio ntpd[1479]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 May 09 15:33:14 volumio systemd[1]: Started Network Time Service. May 09 15:33:14 volumio ntpd[1485]: proto: precision = 0.393 usec (-21) May 09 15:33:14 volumio ntpd[1485]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 09 15:33:14 volumio ntpd[1485]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 09 15:33:14 volumio ntpd[1485]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 864 days ago May 09 15:33:14 volumio ntpd[1485]: Listen and drop on 0 v6wildcard [::]:123 May 09 15:33:14 volumio ntpd[1485]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 09 15:33:14 volumio ntpd[1485]: Listen normally on 2 lo 127.0.0.1:123 May 09 15:33:14 volumio ntpd[1485]: Listen normally on 3 eth0 192.168.0.201:123 May 09 15:33:14 volumio ntpd[1485]: Listening on routing socket on fd #20 for interface updates May 09 15:33:14 volumio ntpd[1485]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 09 15:33:14 volumio ntpd[1485]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 09 15:33:14 volumio sh[630]: forked to background, child pid 1486 May 09 15:33:14 volumio dhcpcd[705]: forked to background, child pid 1486 May 09 15:33:14 volumio volumio[840]: info: Loading i18n strings for locale en May 09 15:33:14 volumio volumio[840]: Updating browse sources language May 09 15:33:14 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:15 volumio winbindd[1411]: [2025/05/09 15:33:15.054820, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 09 15:33:15 volumio winbindd[1411]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 09 15:33:15 volumio systemd[1]: Started Samba Winbind Daemon. May 09 15:33:15 volumio systemd[1]: Starting Samba SMB Daemon... May 09 15:33:15 volumio ifplugd(eth0)[924]: client: ifup: interface eth0 already configured May 09 15:33:15 volumio sh[630]: eth0=eth0 May 09 15:33:15 volumio ifplugd(eth0)[924]: Program executed successfully. May 09 15:33:15 volumio volumio[840]: Starting albumart workers May 09 15:33:15 volumio volumio[840]: Starting albumart workers May 09 15:33:15 volumio volumio[840]: Starting albumart workers May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::initPlayerControls May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:15 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 09 15:33:15 volumio ntpd[1485]: Soliciting pool server 51.89.151.183 May 09 15:33:15 volumio volumio[840]: Express server listening on port 3000 May 09 15:33:15 volumio volumio[840]: [Metrics] WebUI: 11s 457.80ms May 09 15:33:15 volumio volumio[840]: info: Setting Device type: x86 May 09 15:33:16 volumio volumio[840]: info: CoreStateMachine::resetVolumioState May 09 15:33:16 volumio volumio[840]: info: CoreStateMachine::getcurrentVolume May 09 15:33:16 volumio volumio[840]: info: CoreCommandRouter::volumioRetrievevolume May 09 15:33:16 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:16 volumio volumio[840]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 09 15:33:16 volumio volumio[840]: info: CoreStateMachine::getcurrentVolume May 09 15:33:16 volumio volumio[840]: info: CoreCommandRouter::volumioRetrievevolume May 09 15:33:16 volumio volumio[840]: info: Scanning new location : "USB/EFI" May 09 15:33:16 volumio volumio[840]: info: Scanning new location : "INTERNAL/" May 09 15:33:16 volumio volumio[840]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 09 15:33:16 volumio volumio[840]: info: Completed loading Core Plugins May 09 15:33:16 volumio volumio[840]: info: Preparing to generate the ALSA configuration file May 09 15:33:16 volumio volumio[840]: info: Cannot read play queue from file May 09 15:33:16 volumio volumio[840]: info: Volumio Network Manager: Network status updated: 0 May 09 15:33:16 volumio volumio[840]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 09 15:33:16 volumio volumio[840]: wlan0 Interface doesn't support scanning. May 09 15:33:16 volumio volumio[840]: info: Cannot use regular scanning, forcing with ap-force May 09 15:33:16 volumio sudo[1541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 09 15:33:16 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:16 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root May 09 15:33:16 volumio volumio[840]: command failed: No such device (-19) May 09 15:33:16 volumio volumio[840]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 09 15:33:16 volumio volumio[840]: command failed: No such device (-19) May 09 15:33:16 volumio volumio[840]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision May 09 15:33:16 volumio ntpd[1485]: Soliciting pool server 46.101.52.249 May 09 15:33:16 volumio ntpd[1485]: Soliciting pool server 213.5.132.231 May 09 15:33:17 volumio volumio-time-update[656]: volumio-time-update-util: Fetching time from Volumio... May 09 15:33:17 volumio volumio[840]: verbose: New Socket.io Connection to 192.168.0.201 from 192.168.0.197 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 May 09 15:33:17 volumio volumio[840]: verbose: New Socket.io Connection to 192.168.0.201 from 192.168.0.197 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 May 09 15:33:17 volumio volumio[840]: verbose: New Socket.io Connection to 192.168.0.201 from 192.168.0.197 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 May 09 15:33:17 volumio volumio[840]: info: VolumeController:: Volume=41 Mute =false May 09 15:33:17 volumio volumio[840]: info: CoreStateMachine::pushState May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioPushState May 09 15:33:17 volumio volumio-time-update[656]: volumio-time-update-util: Setting system time to: 2025-05-09 15:33:17 May 09 15:33:17 volumio volumio[840]: info: CoreStateMachine::updateTrackBlock May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrackBlock May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioRetrievevolume May 09 15:33:17 volumio sudo[1563]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-05-09 15:33:17 May 09 15:33:17 volumio sudo[1563]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:17 volumio dbus-daemon[679]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.8' (uid=0 pid=1565 comm="timedatectl set-time 2025-05-09 15:33:17 ") May 09 15:33:17 volumio volumio[840]: info: Asound.conf file written May 09 15:33:17 volumio sudo[1572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 09 15:33:17 volumio systemd[1]: Starting Time & Date Service... May 09 15:33:17 volumio sudo[1572]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:17 volumio sudo[1572]: pam_unix(sudo:session): session closed for user root May 09 15:33:17 volumio volumio[840]: No state is present for card Intel May 09 15:33:17 volumio volumio[840]: Found hardware: "HDA-Intel" "Intel CedarTrail HDMI" "HDA:80862880,80860101,00100000 HDA:10ec0888,80862012,00100302" "0x8086" "0x2012" May 09 15:33:17 volumio volumio[840]: Hardware is initialized using a generic method May 09 15:33:17 volumio volumio[840]: No state is present for card Intel May 09 15:33:17 volumio volumio[840]: info: Output device has changed, restarting MPD May 09 15:33:17 volumio volumio[840]: info: Output device has changed, restarting Shairport Sync May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:17 volumio sudo[1579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 09 15:33:17 volumio sudo[1579]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:17 volumio sudo[1581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 09 15:33:17 volumio sudo[1581]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:17 volumio systemd[1]: Stopping Music Player Daemon... May 09 15:33:17 volumio sudo[1579]: pam_unix(sudo:session): session closed for user root May 09 15:33:17 volumio smbd[1510]: [2025/05/09 15:33:17.676027, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 09 15:33:17 volumio smbd[1510]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 09 15:33:17 volumio systemd[1]: Started Samba SMB Daemon. May 09 15:33:17 volumio volumio[840]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 09 15:33:17 volumio volumio[840]: info: ___________ START PLUGINS ___________ May 09 15:33:17 volumio volumio[840]: info: Setting Hotspot Unique name on first start: Volumio-70D3E May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: network , getConfigParam May 09 15:33:17 volumio volumio[840]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getConfigParam] in plugin network May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: network , saveHotspotSettings May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::Reload Ui May 09 15:33:17 volumio volumio[840]: info: ControllerMpd::onStart: Initializing MPD May 09 15:33:17 volumio volumio[840]: info: Creating MPD Configuration file May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 09 15:33:17 volumio volumio[840]: info: [1746804797776] CoreMusicLibrary::Adding element Media Servers May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:17 volumio dbus-daemon[679]: [system] Successfully activated service 'org.freedesktop.timedate1' May 09 15:33:17 volumio systemd[1]: Started Time & Date Service. May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:17 volumio sudo[1592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 09 15:33:17 volumio systemd-timedated[1573]: Changed local time to Fri May 9 15:33:17 2025 May 09 15:33:17 volumio volumio-time-update[656]: volumio-time-update-util: System time updated successfully. May 09 15:33:17 volumio sudo[1590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 09 15:33:17 volumio sudo[1592]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:17 volumio systemd[1]: Started Volumio Time Update Utility. May 09 15:33:17 volumio sudo[1590]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:17 volumio sudo[1563]: pam_unix(sudo:session): session closed for user root May 09 15:33:17 volumio sudo[1590]: pam_unix(sudo:session): session closed for user root May 09 15:33:17 volumio systemd[1]: Reached target Multi-User System. May 09 15:33:17 volumio systemd[1]: Reached target Graphical Interface. May 09 15:33:17 volumio volumio[840]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:17 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... May 09 15:33:17 volumio ntpd[1485]: Soliciting pool server 185.177.149.33 May 09 15:33:17 volumio ntpd[1485]: Soliciting pool server 162.159.200.123 May 09 15:33:17 volumio ntpd[1485]: Soliciting pool server 176.58.115.34 May 09 15:33:17 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 09 15:33:17 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. May 09 15:33:17 volumio volumio[840]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 09 15:33:17 volumio volumio[840]: info: [1746804797133] CoreMusicLibrary::Adding element Last_100 May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 09 15:33:17 volumio volumio[840]: info: [1746804797137] CoreMusicLibrary::Adding element Webradio May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 15:33:17 volumio volumio[840]: info: Initializing BBC Radios May 09 15:33:17 volumio systemd[1]: mpd.service: Succeeded. May 09 15:33:17 volumio systemd[1]: Stopped Music Player Daemon. May 09 15:33:17 volumio systemd[1]: Starting Music Player Daemon... May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:17 volumio volumio[840]: info: Volumio Calling Home May 09 15:33:17 volumio sudo[1606]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 09 15:33:17 volumio sudo[1606]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:17 volumio sudo[1606]: pam_unix(sudo:session): session closed for user root May 09 15:33:17 volumio volumio[840]: info: VolumeController:: Volume=41 Mute =false May 09 15:33:17 volumio volumio[840]: info: CoreStateMachine::pushState May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioPushState May 09 15:33:17 volumio volumio[840]: info: CoreStateMachine::updateTrackBlock May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrackBlock May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioRetrievevolume May 09 15:33:17 volumio volumio[840]: verbose: New Socket.io Connection to 192.168.0.201 from 192.168.0.197 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 09 15:33:17 volumio volumio[840]: info: MPD Permissions set May 09 15:33:17 volumio volumio[840]: info: MPD Permissions set May 09 15:33:17 volumio volumio[840]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 09 15:33:17 volumio volumio[840]: info: VolumeController:: Volume=41 Mute =false May 09 15:33:17 volumio volumio[840]: info: CoreStateMachine::pushState May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioPushState May 09 15:33:17 volumio volumio[840]: info: Volumio called home May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:17 volumio volumio[840]: info: VolumeController:: Volume=41 Mute =false May 09 15:33:17 volumio volumio[840]: info: CoreStateMachine::pushState May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioPushState May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:17 volumio volumio[840]: info: Discovery: adding e862d8e2-a660-4560-bf49-99d03f4deade May 09 15:33:17 volumio volumio[840]: info: Discovery: Found device Volumio May 09 15:33:17 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:17 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:18 volumio sudo[1636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hostapd/hostapd.conf May 09 15:33:18 volumio sudo[1636]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:18 volumio ntpd[1485]: Soliciting pool server 77.74.199.184 May 09 15:33:18 volumio ntpd[1485]: Soliciting pool server 178.215.228.24 May 09 15:33:18 volumio ntpd[1485]: Soliciting pool server 213.210.39.123 May 09 15:33:18 volumio ntpd[1485]: Soliciting pool server 178.215.228.24 May 09 15:33:18 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:18 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:18 volumio sudo[1636]: pam_unix(sudo:session): session closed for user root May 09 15:33:18 volumio volumio[840]: info: Starting Shairport Sync May 09 15:33:18 volumio volumio[840]: info: Starting Shairport Sync May 09 15:33:18 volumio volumio[840]: info: Starting Shairport Sync May 09 15:33:18 volumio sudo[1640]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 09 15:33:18 volumio sudo[1640]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:18 volumio sudo[1642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 09 15:33:18 volumio sudo[1642]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:18 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 09 15:33:18 volumio systemd[1]: shairport-sync.service: Succeeded. May 09 15:33:18 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 09 15:33:18 volumio sudo[1645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 09 15:33:18 volumio sudo[1645]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:18 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 09 15:33:18 volumio volumio[840]: info: Permissions for /etc/hostapd/hostapd.conf May 09 15:33:18 volumio sudo[1640]: pam_unix(sudo:session): session closed for user root May 09 15:33:18 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart May 09 15:33:18 volumio volumio[840]: info: Discovery: Restarting Advertising due to device name change May 09 15:33:18 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 09 15:33:18 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 09 15:33:18 volumio systemd[1]: shairport-sync.service: Succeeded. May 09 15:33:18 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 09 15:33:18 volumio sudo[1650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service May 09 15:33:18 volumio sudo[1650]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:18 volumio volumio[840]: info: Shairport-Sync Started May 09 15:33:18 volumio volumio[840]: Error adding Membership: Error: addMembership EINVAL May 09 15:33:18 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 09 15:33:18 volumio sudo[1642]: pam_unix(sudo:session): session closed for user root May 09 15:33:18 volumio sudo[1645]: pam_unix(sudo:session): session closed for user root May 09 15:33:18 volumio volumio[840]: info: Shairport-Sync Started May 09 15:33:18 volumio volumio[840]: info: Shairport-Sync Started May 09 15:33:18 volumio systemd[1]: Starting Wireless Services... May 09 15:33:19 volumio ntpd[1485]: Soliciting pool server 178.79.140.210 May 09 15:33:19 volumio ntpd[1485]: Soliciting pool server 149.22.220.130 May 09 15:33:19 volumio wireless.js[1653]: WIRELESS: No wireless interface, exiting May 09 15:33:19 volumio iw[1666]: command failed: No such device (-19) May 09 15:33:19 volumio iwconfig[1669]: Error for wireless request "Set Power Management" (8B2C) : May 09 15:33:19 volumio iwconfig[1669]: SET failed on device wlan0 ; No such device. May 09 15:33:19 volumio systemd[1]: wireless.service: Succeeded. May 09 15:33:19 volumio systemd[1]: Started Wireless Services. May 09 15:33:19 volumio sudo[1650]: pam_unix(sudo:session): session closed for user root May 09 15:33:19 volumio volumio[840]: info: Discovery: A device disappeared from network May 09 15:33:19 volumio volumio[840]: info: Discovery: Device volumio disappeared from network May 09 15:33:19 volumio volumio[840]: info: Volumio Network Manager: Network status updated: 1 May 09 15:33:19 volumio mpd[1618]: May 09 15:33 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 09 15:33:19 volumio systemd[1]: Started Music Player Daemon. May 09 15:33:19 volumio systemd[1]: Startup finished in 43.543s (kernel) + 33.094s (userspace) = 1min 16.638s. May 09 15:33:19 volumio sudo[1581]: pam_unix(sudo:session): session closed for user root May 09 15:33:19 volumio sudo[1592]: pam_unix(sudo:session): session closed for user root May 09 15:33:19 volumio volumio[840]: info: Completed starting Core Plugins May 09 15:33:19 volumio volumio[840]: info: ------------------------------------------- May 09 15:33:19 volumio volumio[840]: info: ----- MyVolumio plugins startup ---- May 09 15:33:19 volumio volumio[840]: info: ------------------------------------------- May 09 15:33:19 volumio volumio[840]: info: [MyVolumio PluginManager] Fetching plans data.... May 09 15:33:19 volumio volumio[840]: error: MPD error: The expression evaluated to a falsy value: May 09 15:33:19 volumio volumio[840]: assert.ok(self.idling) May 09 15:33:19 volumio volumio[840]: error: The expression evaluated to a falsy value: May 09 15:33:19 volumio volumio[840]: assert.ok(self.idling) May 09 15:33:20 volumio volumio[840]: error: updateQueue error: null May 09 15:33:20 volumio volumio[840]: info: MPD running with PID1618 May 09 15:33:20 volumio volumio[840]: ,establishing connection May 09 15:33:20 volumio volumio[840]: error: updateQueue error: null May 09 15:33:20 volumio ntpd[1485]: Soliciting pool server 195.171.43.12 May 09 15:33:20 volumio sudo[1691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 09 15:33:20 volumio sudo[1691]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:20 volumio sudo[1691]: pam_unix(sudo:session): session closed for user root May 09 15:33:20 volumio sudo[1693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 09 15:33:20 volumio sudo[1693]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:20 volumio sudo[1693]: pam_unix(sudo:session): session closed for user root May 09 15:33:20 volumio sudo[1697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 09 15:33:20 volumio sudo[1697]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:21 volumio systemd[1]: Started UPnP Renderer front-end to MPD. May 09 15:33:21 volumio sudo[1697]: pam_unix(sudo:session): session closed for user root May 09 15:33:21 volumio volumio[840]: info: Upmpdcli Daemon Started May 09 15:33:21 volumio ntpd[1485]: Soliciting pool server 2a05:b400:c::123:61 May 09 15:33:21 volumio volumio[1701]: Generating RSA private key, 4096 bit long modulus (2 primes) May 09 15:33:21 volumio volumio[1701]: ..........++++ May 09 15:33:22 volumio volumio[1701]: .++++ May 09 15:33:22 volumio volumio[1701]: e is 65537 (0x010001) May 09 15:33:23 volumio ntpd[1485]: receive: Unexpected origin timestamp 0xebc89ec2.199792c8 does not match aorg 0000000000.00000000 from server@185.177.149.33 xmt 0xebc89ec3.6c5e7e1e May 09 15:33:23 volumio ntpd[1485]: receive: Unexpected origin timestamp 0xebc89ec2.1995f05c does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xebc89ec3.6bdcb382 May 09 15:33:23 volumio ntpd[1485]: receive: Unexpected origin timestamp 0xebc89ec2.19940f04 does not match aorg 0000000000.00000000 from server@176.58.115.34 xmt 0xebc89ec3.6b428791 May 09 15:33:23 volumio volumio[1701]: writing RSA key May 09 15:33:23 volumio volumio[840]: verbose: New Socket.io Connection to 192.168.0.201 from 192.168.0.197 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 09 15:33:23 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:23 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:23 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 09 15:33:23 volumio volumio[840]: info: Listing playlists May 09 15:33:23 volumio volumio[840]: info: CoreCommandRouter::volumioGetVisibleSources May 09 15:33:23 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:23 volumio volumio[840]: info: CoreCommandRouter::volumioGetQueue May 09 15:33:23 volumio volumio[840]: info: CoreStateMachine::getQueue May 09 15:33:23 volumio volumio[840]: info: CorePlayQueue::getQueue May 09 15:33:24 volumio volumio[840]: info: Discovery: Started advertising with name: Volumio May 09 15:33:24 volumio volumio-remote-updater[665]: [2025-05-09 15:33:24] [connect] Successful connection May 09 15:33:24 volumio volumio-remote-updater[665]: [2025-05-09 15:33:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746804804 101 May 09 15:33:24 volumio volumio[840]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 7 May 09 15:33:25 volumio systemd[1]: systemd-fsckd.service: Succeeded. May 09 15:33:25 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection May 09 15:33:25 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo May 09 15:33:25 volumio sudo[1737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 09 15:33:25 volumio sudo[1737]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:25 volumio sudo[1737]: pam_unix(sudo:session): session closed for user root May 09 15:33:25 volumio volumio[840]: info: Discovery: adding e862d8e2-a660-4560-bf49-99d03f4deade May 09 15:33:25 volumio volumio[840]: info: Discovery: Found device Volumio May 09 15:33:25 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:25 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:26 volumio volumio[840]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 09 15:33:29 volumio volumio[840]: info: Adding plugin bluetooth to MyMusic Plugins May 09 15:33:29 volumio volumio[840]: info: Adding plugin multiroom to MyMusic Plugins May 09 15:33:29 volumio volumio[840]: info: Adding plugin metavolumio to MyMusic Plugins May 09 15:33:29 volumio volumio[840]: info: Adding plugin cd_controller to MyMusic Plugins May 09 15:33:29 volumio volumio[840]: info: Adding plugin qobuzconnect to MyMusic Plugins May 09 15:33:29 volumio volumio[840]: info: Adding plugin smart_inputs to MyMusic Plugins May 09 15:33:29 volumio volumio[840]: info: Adding plugin tidalconnect to MyMusic Plugins May 09 15:33:29 volumio volumio[840]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 09 15:33:31 volumio volumio[840]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 09 15:33:31 volumio volumio[840]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 09 15:33:31 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:31 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:31 volumio volumio[840]: info: Starting MyVolumio Remote Streaming Endpoints May 09 15:33:31 volumio volumio[840]: info: MyVolumio not started May 09 15:33:31 volumio volumio[840]: info: Initializing device activation check May 09 15:33:31 volumio volumio[840]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 09 15:33:31 volumio volumio[840]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 09 15:33:34 volumio volumio[840]: info: Starting Streaming Service Transparent Proxy May 09 15:33:34 volumio volumio[840]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 09 15:33:34 volumio volumio[840]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 09 15:33:34 volumio volumio[840]: info: Streaming services startup May 09 15:33:34 volumio volumio[840]: info: Starting Streaming Daemon May 09 15:33:34 volumio sudo[1803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 09 15:33:34 volumio sudo[1803]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:34 volumio sudo[1803]: pam_unix(sudo:session): session closed for user root May 09 15:33:34 volumio volumio[840]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 09 15:33:34 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart May 09 15:33:34 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart May 09 15:33:34 volumio volumio[840]: info: Refreshing Cached IP Addresses May 09 15:33:34 volumio sudo[1811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli May 09 15:33:34 volumio sudo[1811]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:34 volumio sudo[1814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 09 15:33:34 volumio sudo[1814]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:34 volumio sudo[1811]: pam_unix(sudo:session): session closed for user root May 09 15:33:34 volumio sudo[1814]: pam_unix(sudo:session): session closed for user root May 09 15:33:34 volumio sudo[1817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 09 15:33:34 volumio sudo[1817]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:34 volumio volumio[840]: error: Cannot start Volumio Streaming Daemon May 09 15:33:34 volumio volumio[840]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 09 15:33:34 volumio volumio[840]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 09 15:33:34 volumio sudo[1817]: pam_unix(sudo:session): session closed for user root May 09 15:33:34 volumio systemd[1]: upmpdcli.service: Succeeded. May 09 15:33:35 volumio dbus-daemon[679]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.15' (uid=0 pid=1747 comm="/usr/lib/chromium/chromium --show-component-extens") May 09 15:33:35 volumio volumio[840]: STREAMING PROXY: Starting server on port 3245 May 09 15:33:35 volumio volumio[840]: Node JS runtime: 14 May 09 15:33:35 volumio systemd[1]: Starting Bluetooth service... May 09 15:33:35 volumio kernel: cryptd: max_cpu_qlen set to 1000 May 09 15:33:37 volumio kernel: Bluetooth: Core ver 2.22 May 09 15:33:37 volumio kernel: NET: Registered PF_BLUETOOTH protocol family May 09 15:33:37 volumio kernel: Bluetooth: HCI device and connection manager initialized May 09 15:33:37 volumio kernel: Bluetooth: HCI socket layer initialized May 09 15:33:37 volumio kernel: Bluetooth: L2CAP socket layer initialized May 09 15:33:37 volumio kernel: Bluetooth: SCO socket layer initialized May 09 15:33:37 volumio bluetoothd[1827]: Bluetooth daemon 5.50 May 09 15:33:37 volumio bluetoothd[1827]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf May 09 15:33:37 volumio dbus-daemon[679]: [system] Successfully activated service 'org.bluez' May 09 15:33:37 volumio systemd[1]: Started Bluetooth service. May 09 15:33:37 volumio bluetoothd[1827]: Starting SDP server May 09 15:33:37 volumio bluetoothd[1827]: Excluding (cli) sap May 09 15:33:37 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 May 09 15:33:37 volumio kernel: Bluetooth: BNEP filters: protocol multicast May 09 15:33:37 volumio kernel: Bluetooth: BNEP socket layer initialized May 09 15:33:37 volumio bluetoothd[1827]: Bluetooth management interface 1.22 initialized May 09 15:33:37 volumio dbus-daemon[679]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.16' (uid=0 pid=1827 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") May 09 15:33:38 volumio systemd[1]: Starting Hostname Service... May 09 15:33:38 volumio dbus-daemon[679]: [system] Successfully activated service 'org.freedesktop.hostname1' May 09 15:33:38 volumio systemd[1]: Started Hostname Service. May 09 15:33:42 volumio volumio[840]: 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/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 09 15:33:43 volumio volumio[840]: info: CoreCommandRouter::volumioGetVisibleSources May 09 15:33:43 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:43 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps May 09 15:33:43 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones May 09 15:33:44 volumio volumio[840]: info: Received Get System Info May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 09 15:33:44 volumio volumio[840]: info: Discovery: Getting this device information May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:44 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 09 15:33:44 volumio volumio-remote-updater[665]: No test mode May 09 15:33:44 volumio volumio-remote-updater[665]: No alpha test mode May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:44 volumio volumio[840]: info: Retrieving Cloud Streaming UI May 09 15:33:44 volumio volumio[840]: info: Getting Tidal Cloud Configuration May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:44 volumio volumio[840]: info: Getting Qobuz Cloud Configuration May 09 15:33:44 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:44 volumio volumio[840]: info: Getting Spotify Cloud Configuration May 09 15:33:44 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:44 volumio volumio[840]: info: Saving Spotify Acccount May 09 15:33:44 volumio volumio[840]: info: Got Tidal Cloud Configuration May 09 15:33:44 volumio volumio[840]: info: Got it May 09 15:33:44 volumio volumio[840]: info: Got it May 09 15:33:44 volumio volumio[840]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 09 15:33:44 volumio volumio[840]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 09 15:33:44 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:44 volumio volumio[840]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 09 15:33:44 volumio sudo[1981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 09 15:33:44 volumio sudo[1981]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:44 volumio sudo[1981]: pam_unix(sudo:session): session closed for user root May 09 15:33:44 volumio sudo[1983]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 09 15:33:44 volumio sudo[1983]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:44 volumio sudo[1983]: pam_unix(sudo:session): session closed for user root May 09 15:33:44 volumio sudo[1990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 09 15:33:44 volumio sudo[1990]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:44 volumio systemd[1]: Started UPnP Renderer front-end to MPD. May 09 15:33:44 volumio sudo[1990]: pam_unix(sudo:session): session closed for user root May 09 15:33:44 volumio volumio[840]: info: Upmpdcli Daemon Started May 09 15:33:45 volumio volumio[1992]: writing RSA key May 09 15:33:45 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 09 15:33:46 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage May 09 15:33:46 volumio volumio[840]: info: Loading i18n strings for locale en May 09 15:33:46 volumio volumio[840]: Updating browse sources language May 09 15:33:46 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:46 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone May 09 15:33:46 volumio volumio[840]: info: Setting timezone to UTC May 09 15:33:46 volumio sudo[2027]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime May 09 15:33:46 volumio sudo[2027]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:46 volumio sudo[2027]: pam_unix(sudo:session): session closed for user root May 09 15:33:46 volumio sudo[2030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/UTC /etc/localtime May 09 15:33:46 volumio sudo[2030]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:46 volumio sudo[2030]: pam_unix(sudo:session): session closed for user root May 09 15:33:46 volumio sudo[2033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime May 09 15:33:46 volumio sudo[2033]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:46 volumio sudo[2033]: pam_unix(sudo:session): session closed for user root May 09 15:33:46 volumio sudo[2036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC May 09 15:33:46 volumio sudo[2036]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:46 volumio systemd-timedated[1573]: Failed to set time zone: Permission denied May 09 15:33:46 volumio sudo[2036]: pam_unix(sudo:session): session closed for user root May 09 15:33:46 volumio volumio[840]: Failed to set time zone: Access denied May 09 15:33:46 volumio volumio[840]: info: Could not set timezone, retrying May 09 15:33:46 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 09 15:33:46 volumio volumio[840]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 09 15:33:46 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:46 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:47 volumio volumio[840]: info: Fetching Streaming Services browse cache May 09 15:33:47 volumio volumio[840]: info: CoreCommandRouter::Close All Modals sent May 09 15:33:47 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:47 volumio volumio[840]: info: Retrieving Cloud Streaming UI May 09 15:33:47 volumio volumio[840]: info: Getting Tidal Cloud Configuration May 09 15:33:47 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:47 volumio volumio[840]: info: Getting Qobuz Cloud Configuration May 09 15:33:47 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:47 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:47 volumio volumio[840]: info: Getting Spotify Cloud Configuration May 09 15:33:47 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:47 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:47 volumio volumio[840]: info: Saving Spotify Acccount May 09 15:33:47 volumio volumio[840]: info: Got Tidal Cloud Configuration May 09 15:33:47 volumio volumio[840]: info: Got it May 09 15:33:47 volumio volumio[840]: info: Got it May 09 15:33:47 volumio volumio[840]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 09 15:33:47 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:47 volumio volumio[840]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 09 15:33:47 volumio sudo[2039]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC May 09 15:33:47 volumio sudo[2039]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:47 volumio sudo[2039]: pam_unix(sudo:session): session closed for user root May 09 15:33:48 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 15:33:48 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:48 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 09 15:33:48 volumio volumio-remote-updater[665]: No test mode May 09 15:33:48 volumio volumio-remote-updater[665]: No alpha test mode May 09 15:33:48 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 09 15:33:48 volumio volumio[840]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 09 15:33:48 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 09 15:33:51 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:51 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:51 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 09 15:33:51 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 09 15:33:51 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 09 15:33:51 volumio volumio[840]: info: CoreCommandRouter::volumioGetBrowseSources May 09 15:33:51 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 15:33:54 volumio volumio[840]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 09 15:33:54 volumio volumio[840]: info: Completed starting MyVolumio Plugin May 09 15:33:54 volumio volumio[840]: [Metrics] CommandRouter: 47s 688.37ms May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::volumiosetStartupVolume May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::Close All Modals sent May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::Close All Modals sent May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Retrieving Cloud Streaming UI May 09 15:33:54 volumio volumio[840]: info: Getting Tidal Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Getting Qobuz Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Getting Spotify Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Saving Spotify Acccount May 09 15:33:54 volumio volumio[840]: info: Got Tidal Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: Got it May 09 15:33:54 volumio volumio[840]: info: Got it May 09 15:33:54 volumio volumio[840]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Retrieving Cloud Streaming UI May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 09 15:33:54 volumio volumio[840]: info: Getting Tidal Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Getting Qobuz Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Getting Spotify Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: info: Saving Spotify Acccount May 09 15:33:54 volumio volumio[840]: info: Got Tidal Cloud Configuration May 09 15:33:54 volumio volumio[840]: info: Got it May 09 15:33:54 volumio volumio[840]: info: Got it May 09 15:33:54 volumio volumio[840]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 09 15:33:54 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:54 volumio volumio[840]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 09 15:33:55 volumio kernel: snd_hda_intel 0000:00:1b.0: IRQ timing workaround is activated for card #0. Suggest a bigger bdl_pos_adj. May 09 15:33:55 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 09 15:33:55 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 09 15:33:55 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 09 15:33:55 volumio volumio[840]: info: Version has changed, forcing UI Reload May 09 15:33:55 volumio volumio[840]: info: CoreCommandRouter::Reload Ui May 09 15:33:56 volumio sudo[2248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 09 15:33:56 volumio sudo[2248]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:56 volumio sudo[2248]: pam_unix(sudo:session): session closed for user root May 09 15:33:56 volumio sudo[2257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 09 15:33:56 volumio sudo[2257]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:56 volumio sudo[2257]: pam_unix(sudo:session): session closed for user root May 09 15:33:56 volumio volumio[840]: 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/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 09 15:33:57 volumio kernel: perf: interrupt took too long (2531 > 2500), lowering kernel.perf_event_max_sample_rate to 79000 May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::volumioGetVisibleSources May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones May 09 15:33:57 volumio volumio[840]: info: Received Get System Info May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 09 15:33:57 volumio volumio[840]: info: Discovery: Getting this device information May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:57 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 09 15:33:57 volumio volumio-remote-updater[665]: No test mode May 09 15:33:57 volumio volumio-remote-updater[665]: No alpha test mode May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Retrieving Cloud Streaming UI May 09 15:33:57 volumio volumio[840]: info: Getting Tidal Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Getting Qobuz Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Getting Spotify Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Saving Spotify Acccount May 09 15:33:57 volumio volumio[840]: info: Got Tidal Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: Got it May 09 15:33:57 volumio volumio[840]: info: Got it May 09 15:33:57 volumio volumio[840]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 09 15:33:57 volumio volumio[840]: verbose: New Socket.io Connection to 192.168.0.201 from 192.168.0.197 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 May 09 15:33:57 volumio volumio[840]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::volumioGetVisibleSources May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones May 09 15:33:57 volumio volumio[840]: info: Received Get System Info May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 09 15:33:57 volumio volumio[840]: info: Discovery: Getting this device information May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::volumioGetState May 09 15:33:57 volumio volumio[840]: info: CorePlayQueue::getTrack 0 May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 09 15:33:57 volumio volumio-remote-updater[665]: No test mode May 09 15:33:57 volumio volumio-remote-updater[665]: No alpha test mode May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Retrieving Cloud Streaming UI May 09 15:33:57 volumio volumio[840]: info: Getting Tidal Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Getting Qobuz Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Getting Spotify Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: Asking plugin for UI Config May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: info: Saving Spotify Acccount May 09 15:33:57 volumio volumio[840]: info: Got Tidal Cloud Configuration May 09 15:33:57 volumio volumio[840]: info: Got it May 09 15:33:57 volumio volumio[840]: info: Got it May 09 15:33:57 volumio volumio[840]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 15:33:57 volumio volumio[840]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 09 15:33:57 volumio volumio[840]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 09 15:33:57 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 09 15:33:58 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 09 15:33:58 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage May 09 15:33:58 volumio volumio[840]: info: Loading i18n strings for locale en May 09 15:33:58 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone May 09 15:33:58 volumio volumio[840]: info: Setting timezone to Europe/London May 09 15:33:58 volumio sudo[2303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime May 09 15:33:58 volumio sudo[2303]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:58 volumio sudo[2303]: pam_unix(sudo:session): session closed for user root May 09 15:33:58 volumio sudo[2306]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/London /etc/localtime May 09 15:33:58 volumio sudo[2306]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:58 volumio sudo[2306]: pam_unix(sudo:session): session closed for user root May 09 15:33:59 volumio sudo[2309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime May 09 15:33:59 volumio sudo[2309]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:59 volumio sudo[2309]: pam_unix(sudo:session): session closed for user root May 09 15:33:59 volumio sudo[2312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/London May 09 15:33:59 volumio sudo[2312]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:59 volumio systemd-timedated[1573]: Failed to set time zone: Permission denied May 09 15:33:59 volumio sudo[2312]: pam_unix(sudo:session): session closed for user root May 09 15:33:59 volumio volumio[840]: Failed to set time zone: Access denied May 09 15:33:59 volumio volumio[840]: info: Could not set timezone, retrying May 09 15:33:59 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 09 15:33:59 volumio volumio[840]: Updating browse sources language May 09 15:33:59 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:59 volumio volumio[840]: info: Fetching Streaming Services browse cache May 09 15:33:59 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage May 09 15:33:59 volumio volumio[840]: info: Loading i18n strings for locale en May 09 15:33:59 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone May 09 15:33:59 volumio volumio[840]: info: Setting timezone to UTC May 09 15:33:59 volumio sudo[2315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime May 09 15:33:59 volumio sudo[2315]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:59 volumio sudo[2315]: pam_unix(sudo:session): session closed for user root May 09 15:33:59 volumio sudo[2318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/UTC /etc/localtime May 09 15:33:59 volumio sudo[2318]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:59 volumio sudo[2318]: pam_unix(sudo:session): session closed for user root May 09 15:33:59 volumio sudo[2321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime May 09 15:33:59 volumio sudo[2321]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:59 volumio sudo[2321]: pam_unix(sudo:session): session closed for user root May 09 15:33:59 volumio sudo[2324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC May 09 15:33:59 volumio sudo[2324]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:33:59 volumio systemd-timedated[1573]: Failed to set time zone: Permission denied May 09 15:33:59 volumio sudo[2324]: pam_unix(sudo:session): session closed for user root May 09 15:33:59 volumio volumio[840]: Failed to set time zone: Access denied May 09 15:33:59 volumio volumio[840]: info: Could not set timezone, retrying May 09 15:33:59 volumio volumio[840]: Updating browse sources language May 09 15:33:59 volumio volumio[840]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 09 15:33:59 volumio volumio[840]: info: Fetching Streaming Services browse cache May 09 15:34:00 volumio sudo[2327]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/London May 09 15:34:00 volumio sudo[2327]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 15:34:00 volumio systemd-timedated[1573]: Failed to set time zone: Permission denied May 09 15:34:00 volumio sudo[2327]: pam_unix(sudo:session): session closed for user root May 09 15:34:00 volumio volumio[840]: Failed to set time zone: Access denied May 09 15:34:00 volumio volumio[840]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 09 15:34:00 volumio volumio[840]: Error: Command failed: /usr/bin/sudo /usr/bin/timedatectl set-timezone 'Europe/London' May 09 15:34:00 volumio volumio[840]: Failed to set time zone: Access denied May 09 15:34:00 volumio volumio[840]: at checkExecSyncError (child_process.js:790:11) May 09 15:34:00 volumio volumio[840]: at execSync (child_process.js:863:15) May 09 15:34:00 volumio volumio[840]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/system/index.js:1575:9) May 09 15:34:00 volumio volumio[840]: at listOnTimeout (internal/timers.js:557:17) May 09 15:34:00 volumio volumio[840]: at processTimers (internal/timers.js:500:7) { May 09 15:34:00 volumio volumio[840]: status: 1, May 09 15:34:00 volumio volumio[840]: signal: null, May 09 15:34:00 volumio volumio[840]: output: [ null, '', 'Failed to set time zone: Access denied\n' ], May 09 15:34:00 volumio volumio[840]: pid: 2326, May 09 15:34:00 volumio volumio[840]: stdout: '', May 09 15:34:00 volumio volumio[840]: stderr: 'Failed to set time zone: Access denied\n' May 09 15:34:00 volumio volumio[840]: } May 09 15:34:00 volumio volumio[840]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 09 15:34:00 volumio sudo[2338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-09 15:33 May 09 15:34:00 volumio sudo[2338]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 12:21:23 PM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="a9588e47e4b05f1a05bf70b4acc7555c"