-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2025-05-01 08:10:11 CEST. -- May 01 08:09:35 damien systemd-timedated[1161]: Changed local time to Thu May 1 08:09:35 2025 May 01 08:09:35 damien sudo[1155]: pam_unix(sudo:session): session closed for user root May 01 08:09:35 damien systemd[1]: Starting Daily apt download activities... May 01 08:09:35 damien systemd[1]: Starting Daily man-db regeneration... May 01 08:09:35 damien volumio-time-update[542]: volumio-time-update-util: System time updated successfully. May 01 08:09:35 damien systemd[1]: Started Volumio Time Update Utility. May 01 08:09:35 damien systemd[1]: man-db.service: Succeeded. May 01 08:09:35 damien systemd[1]: Started Daily man-db regeneration. May 01 08:09:35 damien ntpd[1137]: Soliciting pool server 162.159.200.123 May 01 08:09:35 damien wireless.js[543]: trying... May 01 08:09:35 damien sudo[1189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:35 damien sudo[1189]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:35 damien sudo[1189]: pam_unix(sudo:session): session closed for user root May 01 08:09:36 damien nmbd[835]: [2025/05/01 08:09:36.259394, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 01 08:09:36 damien systemd[1]: Started Samba NMB Daemon. May 01 08:09:36 damien kernel: nf_conntrack: automatic helper assignment is deprecated and it will be removed soon. Use the iptables CT target to attach helpers instead. May 01 08:09:36 damien systemd[1]: Starting Samba Winbind Daemon... May 01 08:09:36 damien nmbd[835]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 01 08:09:36 damien ntpd[1137]: Soliciting pool server 45.132.96.81 May 01 08:09:36 damien ntpd[1137]: Soliciting pool server 195.154.226.102 May 01 08:09:36 damien systemd[1]: apt-daily.service: Succeeded. May 01 08:09:36 damien systemd[1]: Started Daily apt download activities. May 01 08:09:36 damien systemd[1]: Starting Daily apt upgrade and clean activities... May 01 08:09:36 damien wireless.js[543]: trying... May 01 08:09:36 damien sudo[1232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:36 damien sudo[1232]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:36 damien sudo[1232]: pam_unix(sudo:session): session closed for user root May 01 08:09:36 damien winbindd[1215]: [2025/05/01 08:09:36.515029, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 01 08:09:36 damien winbindd[1215]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 01 08:09:36 damien winbindd[1215]: [2025/05/01 08:09:36.523478, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 01 08:09:36 damien systemd[1]: Started Samba Winbind Daemon. May 01 08:09:36 damien winbindd[1215]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 01 08:09:36 damien systemd[1]: Starting Samba SMB Daemon... May 01 08:09:36 damien smbd[1257]: [2025/05/01 08:09:36.889164, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 01 08:09:36 damien systemd[1]: Started Samba SMB Daemon. May 01 08:09:36 damien smbd[1257]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 01 08:09:37 damien ntpd[1137]: Soliciting pool server 194.177.34.116 May 01 08:09:37 damien ntpd[1137]: Soliciting pool server 82.64.230.205 May 01 08:09:37 damien ntpd[1137]: Soliciting pool server 162.159.200.1 May 01 08:09:37 damien wireless.js[543]: trying... May 01 08:09:37 damien systemd[1]: apt-daily-upgrade.service: Succeeded. May 01 08:09:37 damien systemd[1]: Started Daily apt upgrade and clean activities. May 01 08:09:37 damien sudo[1299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:37 damien sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:37 damien sudo[1299]: pam_unix(sudo:session): session closed for user root May 01 08:09:37 damien volumio-remote-updater[556]: [2025-05-01 08:09:37] [info] asio async_connect error: system:111 (Connection refused) May 01 08:09:37 damien volumio-remote-updater[556]: [2025-05-01 08:09:37] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) May 01 08:09:37 damien volumio-remote-updater[556]: [2025-05-01 08:09:37] [error] handle_connect error: Underlying Transport Error May 01 08:09:38 damien ntpd[1137]: Soliciting pool server 82.65.248.56 May 01 08:09:38 damien ntpd[1137]: Soliciting pool server 51.68.44.27 May 01 08:09:38 damien ntpd[1137]: Soliciting pool server 82.66.40.79 May 01 08:09:38 damien ntpd[1137]: Soliciting pool server 82.67.41.119 May 01 08:09:38 damien wireless.js[543]: trying... May 01 08:09:38 damien sudo[1313]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:38 damien sudo[1313]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:38 damien sudo[1313]: pam_unix(sudo:session): session closed for user root May 01 08:09:39 damien ntpd[1137]: Soliciting pool server 51.75.18.118 May 01 08:09:39 damien ntpd[1137]: Soliciting pool server 5.135.158.34 May 01 08:09:39 damien ntpd[1137]: Soliciting pool server 82.67.126.242 May 01 08:09:39 damien wireless.js[543]: trying... May 01 08:09:39 damien sudo[1323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:39 damien sudo[1323]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:39 damien sudo[1323]: pam_unix(sudo:session): session closed for user root May 01 08:09:40 damien ntpd[1137]: Soliciting pool server 62.210.124.230 May 01 08:09:40 damien wireless.js[543]: trying... May 01 08:09:40 damien sudo[1333]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:40 damien sudo[1333]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:40 damien sudo[1333]: pam_unix(sudo:session): session closed for user root May 01 08:09:41 damien ntpd[1137]: Soliciting pool server 2001:41d0:203:7c03:2002:2002:2002:2002 May 01 08:09:41 damien wireless.js[543]: trying... May 01 08:09:41 damien sudo[1343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:41 damien sudo[1343]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:41 damien sudo[1343]: pam_unix(sudo:session): session closed for user root May 01 08:09:42 damien wireless.js[543]: trying... May 01 08:09:42 damien sudo[1353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:42 damien sudo[1353]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:42 damien sudo[1353]: pam_unix(sudo:session): session closed for user root May 01 08:09:43 damien wireless.js[543]: trying... May 01 08:09:43 damien sudo[1363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:43 damien sudo[1363]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:43 damien sudo[1363]: pam_unix(sudo:session): session closed for user root May 01 08:09:45 damien ntpd[1137]: receive: Unexpected origin timestamp 0xebbd8ea8.568be9ed does not match aorg 0000000000.00000000 from server@195.154.226.102 xmt 0xebbd8ea9.414c6271 May 01 08:09:45 damien ntpd[1137]: receive: Unexpected origin timestamp 0xebbd8ea8.564a38ba does not match aorg 0000000000.00000000 from server@82.67.126.242 xmt 0xebbd8ea9.4100ca96 May 01 08:09:45 damien ntpd[1137]: receive: Unexpected origin timestamp 0xebbd8ea8.5665788e does not match aorg 0000000000.00000000 from server@51.68.44.27 xmt 0xebbd8ea9.4197d642 May 01 08:09:45 damien ntpd[1137]: receive: Unexpected origin timestamp 0xebbd8ea8.5698a707 does not match aorg 0000000000.00000000 from server@45.132.96.81 xmt 0xebbd8ea9.420f37d8 May 01 08:09:45 damien ntpd[1137]: receive: Unexpected origin timestamp 0xebbd8ea8.56329e00 does not match aorg 0000000000.00000000 from server@51.75.18.118 xmt 0xebbd8ea9.42319b89 May 01 08:09:45 damien ntpd[1137]: receive: Unexpected origin timestamp 0xebbd8ea8.5658632a does not match aorg 0000000000.00000000 from server@82.65.248.56 xmt 0xebbd8ea9.45995814 May 01 08:09:45 damien wireless.js[543]: trying... May 01 08:09:45 damien sudo[1373]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:45 damien sudo[1373]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:45 damien sudo[1373]: pam_unix(sudo:session): session closed for user root May 01 08:09:46 damien wireless.js[543]: trying... May 01 08:09:46 damien sudo[1383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:46 damien sudo[1383]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:46 damien sudo[1383]: pam_unix(sudo:session): session closed for user root May 01 08:09:47 damien wireless.js[543]: trying... May 01 08:09:47 damien sudo[1393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:47 damien sudo[1393]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:47 damien sudo[1393]: pam_unix(sudo:session): session closed for user root May 01 08:09:48 damien wireless.js[543]: trying... May 01 08:09:48 damien sudo[1403]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 01 08:09:48 damien sudo[1403]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:48 damien sudo[1403]: pam_unix(sudo:session): session closed for user root May 01 08:09:48 damien volumio-remote-updater[556]: [2025-05-01 08:09:48] [info] asio async_connect error: system:111 (Connection refused) May 01 08:09:48 damien volumio-remote-updater[556]: [2025-05-01 08:09:48] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) May 01 08:09:48 damien volumio-remote-updater[556]: [2025-05-01 08:09:48] [error] handle_connect error: Underlying Transport Error May 01 08:09:49 damien wireless.js[543]: Overtime, starting plan B May 01 08:09:49 damien wireless.js[543]: STARTING HOTSPOT May 01 08:09:49 damien wpa_supplicant[961]: nl80211: Failed to open /proc/sys/net/ipv4/conf/wlan0/drop_unicast_in_l2_multicast: No such file or directory May 01 08:09:49 damien wpa_supplicant[961]: nl80211: Failed to set IPv4 unicast in multicast filter May 01 08:09:49 damien wpa_supplicant[961]: nl80211: Failed to open /proc/sys/net/ipv4/conf/wlan0/drop_unicast_in_l2_multicast: No such file or directory May 01 08:09:49 damien wpa_supplicant[961]: nl80211: Failed to set IPv4 unicast in multicast filter May 01 08:09:49 damien wpa_supplicant[961]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 May 01 08:09:49 damien wpa_supplicant[961]: wlan0: CTRL-EVENT-TERMINATING May 01 08:09:52 damien sudo[1422]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 01 08:09:52 damien sudo[1422]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:52 damien sudo[1422]: pam_unix(sudo:session): session closed for user root May 01 08:09:52 damien sudo[1431]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 01 08:09:52 damien sudo[1431]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:52 damien sudo[1431]: pam_unix(sudo:session): session closed for user root May 01 08:09:52 damien avahi-daemon[548]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. May 01 08:09:52 damien avahi-daemon[548]: New relevant interface wlan0.IPv4 for mDNS. May 01 08:09:52 damien avahi-daemon[548]: Registering new address record for 192.168.211.1 on wlan0.IPv4. May 01 08:09:52 damien systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... May 01 08:09:52 damien hostapd[1444]: Configuration file: /etc/hostapd/hostapd.conf May 01 08:09:52 damien hostapd[1444]: Using interface wlan0 with hwaddr 70:66:55:76:4e:d3 and ssid "Volumio-9E1E6" May 01 08:09:52 damien dhcpcd[1138]: wlan0: carrier acquired May 01 08:09:52 damien hostapd[1444]: wlan0: interface state UNINITIALIZED->ENABLED May 01 08:09:52 damien hostapd[1444]: wlan0: AP-ENABLED May 01 08:09:52 damien systemd[1]: hostapd.service: Can't open PID file /run/hostapd.pid (yet?) after start: No such file or directory May 01 08:09:52 damien systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. May 01 08:09:52 damien dhcpcd[1138]: wlan0: IAID 55:76:4e:d3 May 01 08:09:52 damien dhcpcd[1138]: wlan0: adding address fe80::7266:55ff:fe76:4ed3 May 01 08:09:52 damien dhcpcd[1138]: ipv6_addaddr1: Permission denied May 01 08:09:52 damien systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... May 01 08:09:52 damien iwconfig[1449]: Error for wireless request "Set Power Management" (8B2C) : May 01 08:09:52 damien iwconfig[1449]: SET failed on device wlan0 ; Operation not permitted. May 01 08:09:52 damien systemd[1]: wireless.service: Succeeded. May 01 08:09:52 damien systemd[1]: Started Wireless Services. May 01 08:09:52 damien dnsmasq[1447]: dnsmasq: syntax check OK. May 01 08:09:52 damien systemd[1]: Started Volumio Backend Module. May 01 08:09:52 damien systemd[1]: Started Volumio Cpu Tweaker. May 01 08:09:52 damien systemd[1]: Reached target Multi-User System. May 01 08:09:52 damien systemd[1]: Reached target Graphical Interface. May 01 08:09:52 damien systemd[1]: Starting Update UTMP about System Runlevel Changes... May 01 08:09:52 damien volumio-cpu-tweak[1451]: Setting RT Priority for mpd May 01 08:09:52 damien volumio-cpu-tweak[1451]: Setting MPD Affinity May 01 08:09:52 damien volumio-cpu-tweak[1451]: pid 883's current affinity mask: f May 01 08:09:52 damien volumio-cpu-tweak[1451]: pid 883's new affinity mask: 3 May 01 08:09:52 damien systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 01 08:09:52 damien systemd[1]: Started Update UTMP about System Runlevel Changes. May 01 08:09:52 damien volumio-cpu-tweak[1451]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input May 01 08:09:52 damien volumio-cpu-tweak[1451]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance May 01 08:09:52 damien systemd[1]: volumio_cpu_tweak.service: Succeeded. May 01 08:09:53 damien dnsmasq[1474]: started, version 2.80 cachesize 150 May 01 08:09:53 damien dnsmasq[1474]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile May 01 08:09:53 damien dnsmasq-dhcp[1474]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d May 01 08:09:53 damien dnsmasq[1474]: reading /etc/resolv.conf May 01 08:09:53 damien dnsmasq[1474]: using nameserver 192.168.1.254#53 May 01 08:09:53 damien dnsmasq[1474]: using nameserver 208.67.222.222#53 May 01 08:09:53 damien dnsmasq[1474]: using nameserver 208.67.220.220#53 May 01 08:09:53 damien dnsmasq[1474]: read /etc/hosts - 1 addresses May 01 08:09:53 damien systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. May 01 08:09:53 damien systemd[1]: Reached target Host and Network Name Lookups. May 01 08:09:53 damien systemd[1]: Startup finished in 14.577s (kernel) + 29.806s (userspace) = 44.384s. May 01 08:09:53 damien dhcpcd[1138]: wlan0: soliciting a DHCP lease May 01 08:09:53 damien dhcpcd[1138]: wlan0: soliciting an IPv6 router May 01 08:09:54 damien ntpd[1137]: Listen normally on 4 wlan0 192.168.211.1:123 May 01 08:09:54 damien ntpd[1137]: new interface(s) found: waking up resolver May 01 08:09:54 damien volumio[1450]: info: ------------------------------------------- May 01 08:09:54 damien volumio[1450]: info: ----- Volumio3 ---- May 01 08:09:54 damien volumio[1450]: info: ------------------------------------------- May 01 08:09:54 damien volumio[1450]: info: ----- System startup ---- May 01 08:09:54 damien volumio[1450]: info: ------------------------------------------- May 01 08:09:54 damien systemd[1]: systemd-fsckd.service: Succeeded. May 01 08:09:55 damien volumio[1450]: info: MYVOLUMIO Environment detected May 01 08:09:55 damien volumio[1450]: info: Plugin folders cleanup May 01 08:09:55 damien volumio[1450]: info: Scanning into folder /volumio/app/plugins/ May 01 08:09:55 damien volumio[1450]: info: Scanning category audio_interface May 01 08:09:55 damien volumio[1450]: info: Scanning category miscellanea May 01 08:09:55 damien volumio[1450]: info: Scanning category music_service May 01 08:09:55 damien volumio[1450]: info: Scanning category plugins.json May 01 08:09:55 damien volumio[1450]: info: Scanning category system_controller May 01 08:09:55 damien volumio[1450]: info: Scanning category user_interface May 01 08:09:55 damien volumio[1450]: info: Scanning into folder /data/plugins/ May 01 08:09:55 damien volumio[1450]: info: Scanning category audio_interface May 01 08:09:55 damien volumio[1450]: info: Scanning category music_service May 01 08:09:55 damien volumio[1450]: info: Scanning category user_interface May 01 08:09:55 damien volumio[1450]: info: Plugin folders cleanup completed May 01 08:09:55 damien volumio[1450]: info: ------------------------------------------- May 01 08:09:55 damien volumio[1450]: info: ----- Core plugins startup ---- May 01 08:09:55 damien volumio[1450]: info: ------------------------------------------- May 01 08:09:55 damien volumio[1450]: info: Loading plugins from folder /volumio/app/plugins/ May 01 08:09:55 damien volumio[1450]: info: Adding plugin upnp to MyMusic Plugins May 01 08:09:55 damien volumio[1450]: info: Adding plugin airplay_emulation to MyMusic Plugins May 01 08:09:55 damien volumio[1450]: info: Adding plugin upnp_browser to MyMusic Plugins May 01 08:09:55 damien volumio[1450]: info: Loading plugins from folder /data/plugins/ May 01 08:09:55 damien volumio[1450]: info: Loading plugin "system"... May 01 08:09:55 damien volumio[1450]: info: Loading plugin "appearance"... May 01 08:09:56 damien volumio[1450]: info: Loading plugin "network"... May 01 08:09:56 damien volumio[1450]: info: Refreshing Cached IP Addresses May 01 08:09:56 damien sudo[1494]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 01 08:09:56 damien volumio[1450]: info: Loading plugin "services"... May 01 08:09:56 damien sudo[1496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 01 08:09:56 damien volumio[1450]: info: Loading plugin "alsa_controller"... May 01 08:09:56 damien sudo[1496]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:56 damien sudo[1507]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 01 08:09:56 damien sudo[1494]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:56 damien sudo[1496]: pam_unix(sudo:session): session closed for user root May 01 08:09:56 damien sudo[1494]: pam_unix(sudo:session): session closed for user root May 01 08:09:56 damien sudo[1507]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:09:56 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 01 08:09:56 damien volumio[1450]: info: Loading plugin "wizard"... May 01 08:09:56 damien volumio[1450]: info: Loading plugin "networkfs"... May 01 08:09:56 damien volumio[1450]: info: Starting Udev Watcher for removable devices May 01 08:09:56 damien volumio[1450]: info: Ignoring mount for partition: BOOT May 01 08:09:56 damien volumio[1450]: info: Ignoring mount for partition: volumio May 01 08:09:56 damien volumio[1450]: info: Ignoring mount for partition: volumio_data May 01 08:09:56 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 01 08:09:56 damien volumio[1450]: info: Loading plugin "volumio_command_line_client"... May 01 08:09:56 damien volumio[1450]: info: Loading plugin "upnp"... May 01 08:09:56 damien volumio[1450]: info: [1746079796239] Starting Upmpd Daemon May 01 08:09:56 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 01 08:09:56 damien volumio[1450]: info: Loading plugin "my_music"... May 01 08:09:56 damien volumio[1450]: info: Loading plugin "mpd"... May 01 08:09:56 damien sudo[1507]: pam_unix(sudo:session): session closed for user root May 01 08:09:56 damien volumio[1450]: info: Loading plugin "upnp_browser"... May 01 08:09:56 damien systemd[1]: systemd-hostnamed.service: Succeeded. May 01 08:09:56 damien volumio[1450]: info: Loading plugin "alarm-clock"... May 01 08:09:56 damien volumio[1450]: info: Loading plugin "airplay_emulation"... May 01 08:09:56 damien volumio[1450]: info: Starting Shairport Sync May 01 08:09:56 damien volumio[1450]: info: Loading plugin "last_100"... May 01 08:09:56 damien volumio[1450]: info: Loading plugin "webradio"... May 01 08:09:56 damien volumio[1450]: info: Loading plugin "i2s_dacs"... May 01 08:09:56 damien volumio[1450]: info: I2S DAC not set, start Auto-detection May 01 08:09:56 damien volumio[1450]: info: Loading plugin "volumiodiscovery"... May 01 08:09:57 damien volumio[1450]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 01 08:09:57 damien volumio[1450]: *** WARNING *** Please fix your application to use the native API of Avahi! May 01 08:09:57 damien volumio[1450]: *** WARNING *** For more information see May 01 08:09:57 damien volumio[1450]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 01 08:09:57 damien volumio[1450]: *** WARNING *** Please fix your application to use the native API of Avahi! May 01 08:09:57 damien volumio[1450]: *** WARNING *** For more information see May 01 08:09:57 damien node[1450]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 01 08:09:57 damien node[1450]: *** WARNING *** Please fix your application to use the native API of Avahi! May 01 08:09:57 damien node[1450]: *** WARNING *** For more information see May 01 08:09:57 damien node[1450]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 01 08:09:57 damien node[1450]: *** WARNING *** Please fix your application to use the native API of Avahi! May 01 08:09:57 damien node[1450]: *** WARNING *** For more information see May 01 08:09:57 damien volumio[1450]: info: Applying required configuration parameters for plugin volumiodiscovery May 01 08:09:57 damien volumio[1450]: info: Discovery: Started advertising with name: Damien May 01 08:09:57 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 01 08:09:57 damien volumio[1450]: info: Loading plugin "spop"... May 01 08:09:57 damien volumio[1450]: info: Loading plugin "ytmusic"... May 01 08:09:58 damien dhcpcd[1138]: wlan0: probing for an IPv4LL address May 01 08:09:58 damien volumio[1450]: info: Loading plugin "now_playing"... May 01 08:09:58 damien volumio-remote-updater[556]: [2025-05-01 08:09:58] [connect] Successful connection May 01 08:09:59 damien volumio[1450]: info: Loading plugin "outputs"... May 01 08:09:59 damien volumio[1450]: info: Loading plugin "albumart"... May 01 08:09:59 damien volumio[1450]: info: Plugin example_plugin is not enabled May 01 08:09:59 damien volumio[1450]: info: Loading plugin "inputs"... May 01 08:09:59 damien volumio[1450]: info: Loading plugin "updater_comm"... May 01 08:09:59 damien volumio[1450]: info: Plugin mpdemulation is not enabled May 01 08:09:59 damien volumio[1450]: info: Loading plugin "rest_api"... May 01 08:09:59 damien volumio[1450]: info: Loading plugin "websocket"... May 01 08:09:59 damien volumio[1450]: info: Starting Socket.io Server version 2.3.0 May 01 08:09:59 damien volumio[1450]: info: Loading plugin "fusiondsp"... May 01 08:09:59 damien volumio[1450]: Forking 3 albumart workers May 01 08:09:59 damien volumio[1450]: info: Applying required configuration parameters for plugin fusiondsp May 01 08:09:59 damien volumio[1450]: info: Loading plugin "lms"... May 01 08:10:00 damien volumio[1450]: info: Loading plugin "podcast"... May 01 08:10:00 damien volumio[1450]: Starting albumart workers May 01 08:10:00 damien volumio[1450]: Starting albumart workers May 01 08:10:00 damien volumio[1450]: info: ControllerPodcast::constructor May 01 08:10:00 damien volumio[1450]: Starting albumart workers May 01 08:10:00 damien volumio[1450]: info: Loading plugin "peppyspectrum"... May 01 08:10:00 damien volumio[1450]: info: Loading plugin "randomizer"... May 01 08:10:00 damien volumio[1450]: info: Applying required configuration parameters for plugin randomizer May 01 08:10:00 damien volumio[1450]: info: Loading i18n strings for locale fr May 01 08:10:00 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored. May 01 08:10:00 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. May 01 08:10:00 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 01 08:10:00 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 01 08:10:00 damien volumio[1450]: Updating browse sources language May 01 08:10:00 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::initPlayerControls May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 08:10:01 damien volumio[1450]: Express server listening on port 3000 May 01 08:10:01 damien volumio[1450]: [Metrics] WebUI: 7s 223.19ms May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::resetVolumioState May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::getcurrentVolume May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioRetrievevolume May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:01 damien volumio[1450]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 01 08:10:01 damien volumio[1450]: info: Completed loading Core Plugins May 01 08:10:01 damien volumio[1450]: info: Preparing to generate the ALSA configuration file May 01 08:10:01 damien volumio[1450]: info: Volumio Network Manager: Network status updated: 1 May 01 08:10:01 damien volumio[1450]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 01 08:10:01 damien volumio[1450]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 01 08:10:01 damien volumio[1450]: info: Reading ALSA contributions from plugins. May 01 08:10:01 damien volumio-remote-updater[556]: [2025-05-01 08:10:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746079798 101 May 01 08:10:01 damien volumio[1450]: 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: 1 May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::setRepeat true single undefined May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::pushState May 01 08:10:01 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioPushState May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::setRandom null May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::pushState May 01 08:10:01 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioPushState May 01 08:10:01 damien volumio[1450]: info: Setting Device type: Tinkerboard May 01 08:10:01 damien volumio[1450]: info: VolumeController:: Volume=60 Mute =false May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::pushState May 01 08:10:01 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioPushState May 01 08:10:01 damien volumio[1450]: info: CoreStateMachine::updateTrackBlock May 01 08:10:01 damien volumio[1450]: info: CorePlayQueue::getTrackBlock May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioRetrievevolume May 01 08:10:01 damien volumio[1450]: info: Asound.conf file unchanged, so no further update is needed May 01 08:10:01 damien volumio[1450]: info: Output device has changed, restarting MPD May 01 08:10:01 damien volumio[1450]: info: Output device has changed, restarting Shairport Sync May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:01 damien sudo[1624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 08:10:01 damien sudo[1626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 08:10:01 damien sudo[1624]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:01 damien sudo[1626]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:01 damien sudo[1624]: pam_unix(sudo:session): session closed for user root May 01 08:10:01 damien volumio[1450]: info: ___________ START PLUGINS ___________ May 01 08:10:01 damien volumio[1450]: info: ControllerMpd::onStart: Initializing MPD May 01 08:10:01 damien volumio[1450]: info: Creating MPD Configuration file May 01 08:10:01 damien systemd[1]: Stopping Music Player Daemon... May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 01 08:10:01 damien volumio[1450]: info: [1746079801473] CoreMusicLibrary::Adding element Serveurs Média May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:01 damien sudo[1644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 08:10:01 damien sudo[1644]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:01 damien sudo[1647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:01 damien sudo[1644]: pam_unix(sudo:session): session closed for user root May 01 08:10:01 damien sudo[1647]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 01 08:10:01 damien volumio[1450]: info: [1746079801571] CoreMusicLibrary::Adding element Last_100 May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 01 08:10:01 damien volumio[1450]: info: [1746079801573] CoreMusicLibrary::Adding element Webradio May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 01 08:10:01 damien volumio[1450]: info: Initializing BBC Radios May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:01 damien volumio[1450]: info: Creating Spotify config file May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien systemd[1]: mpd.service: Succeeded. May 01 08:10:01 damien systemd[1]: Stopped Music Player Daemon. May 01 08:10:01 damien systemd[1]: Starting Music Player Daemon... May 01 08:10:01 damien sudo[1676]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 01 08:10:01 damien volumio[1450]: info: [1746079801691] CoreMusicLibrary::Adding element YouTube Music May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:01 damien volumio[1450]: Cannot find translation for source YouTube Music May 01 08:10:01 damien sudo[1676]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:01 damien sudo[1676]: pam_unix(sudo:session): session closed for user root May 01 08:10:01 damien volumio[1450]: info: [now-playing] ConfigUpdater: config is up to date. May 01 08:10:01 damien volumio[1450]: info: Loading i18n strings for locale fr May 01 08:10:01 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored. May 01 08:10:01 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. May 01 08:10:01 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 01 08:10:01 damien volumio[1450]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: FusionDsp - mixtype--------------------- Hardware May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 01 08:10:01 damien volumio[1450]: info: [1746079801738] CoreMusicLibrary::Adding element Podcast May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:01 damien volumio[1450]: Cannot find translation for source YouTube Music May 01 08:10:01 damien volumio[1450]: Cannot find translation for source Podcast May 01 08:10:01 damien sudo[1686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 01 08:10:01 damien sudo[1686]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 01 08:10:01 damien volumio[1450]: info: [1746079801775] CoreMusicLibrary::Adding element Randomizer May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:01 damien volumio[1450]: Cannot find translation for source YouTube Music May 01 08:10:01 damien volumio[1450]: Cannot find translation for source Podcast May 01 08:10:01 damien volumio[1450]: Cannot find translation for source Randomizer May 01 08:10:01 damien systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. May 01 08:10:01 damien volumio[1450]: info: Volumio Calling Home May 01 08:10:01 damien systemd[1]: Starting Logitech Media Server Daemon... May 01 08:10:01 damien systemd[1]: Started Logitech Media Server Daemon. May 01 08:10:01 damien sudo[1686]: pam_unix(sudo:session): session closed for user root May 01 08:10:01 damien systemd[1697]: logitechmediaserver.service: Failed to execute command: No such file or directory May 01 08:10:01 damien systemd[1697]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 01 08:10:01 damien systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 01 08:10:01 damien systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 01 08:10:01 damien volumio[1450]: info: Preparing to generate the ALSA configuration file May 01 08:10:01 damien volumio[1450]: info: [now-playing] App is listening on port 4004. May 01 08:10:01 damien volumio[1450]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds May 01 08:10:01 damien volumio[1450]: info: Discovery: adding 1c81eb01-8a63-4474-ac3c-50ffb2495255 May 01 08:10:01 damien volumio[1450]: info: Discovery: Found device Damien May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioGetState May 01 08:10:01 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:01 damien volumio[1450]: info: Discovery: this is already registered, 1c81eb01-8a63-4474-ac3c-50ffb2495255 May 01 08:10:01 damien volumio[1450]: info: Discovery: Found device Damien May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::volumioGetState May 01 08:10:01 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:01 damien volumio[1450]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 01 08:10:01 damien volumio[1450]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 01 08:10:01 damien volumio[1450]: info: Reading ALSA contributions from plugins. May 01 08:10:01 damien volumio[1450]: info: logitechmediaserver started May 01 08:10:01 damien volumio[1450]: info: MPD Permissions set May 01 08:10:01 damien volumio[1450]: info: MPD Permissions set May 01 08:10:01 damien volumio[1450]: info: Spotify config file written May 01 08:10:01 damien sudo[1704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 01 08:10:01 damien volumio[1450]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 01 08:10:01 damien volumio[1450]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 01 08:10:01 damien sudo[1704]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:01 damien volumio[1450]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:01 damien systemd[1]: Started go-librespot Daemon. May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 01 08:10:02 damien sudo[1704]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien go-librespot[1714]: Librespot-go daemon starting... May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: No need to fix Spotify hosts May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=info msg="generated new device id: ff5a9815effc6e3371e38ccf8c34bec0fc7e80c8" May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=debug msg="stored credentials found for 1cu1z4j2f4w4r5m6jg8tlx0qq" May 01 08:10:02 damien volumio[1450]: info: VolumeController:: Volume=60 Mute =false May 01 08:10:02 damien volumio[1450]: info: CoreStateMachine::pushState May 01 08:10:02 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::volumioPushState May 01 08:10:02 damien volumio[1450]: info: Volumio called home May 01 08:10:02 damien volumio[1450]: info: Starting Shairport Sync May 01 08:10:02 damien volumio[1450]: info: Starting Shairport Sync May 01 08:10:02 damien volumio[1450]: info: Starting Shairport Sync May 01 08:10:02 damien sudo[1733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 08:10:02 damien volumio[1450]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 01 08:10:02 damien volumio[1450]: SPOTIFY: BQC2avujwWB3I5Coa40m23Pdu8Mq-0YKh64fZbYyFItlf6FeelxKFKGFQ51lWJ1kNxXoCpnYWA1qtH15DiKSP-CqY0QiAHWNgjxx54kmLQrsPXbnGFIk79WMl3hq0VYmzY9uYP723eRQUnYCHAvE_KL9wPXfGQsqEAF8GnCdPSel7UUuvzXgcE2U0QolkxcVo3-9KIVd3zmLQ6HJPjwFqJF7RSwryIbFPFklvTpbrZzlORkLWk8nwB-1LUSlip_4PjZE2gKXe_iy23q5P8LfeoBWrH17tZAcGeB3U7g5C6I May 01 08:10:02 damien volumio[1450]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 01 08:10:02 damien volumio[1450]: info: New Spotify access token = BQC2avujwWB3I5Coa40m23Pdu8Mq-0YKh64fZbYyFItlf6FeelxKFKGFQ51lWJ1kNxXoCpnYWA1qtH15DiKSP-CqY0QiAHWNgjxx54kmLQrsPXbnGFIk79WMl3hq0VYmzY9uYP723eRQUnYCHAvE_KL9wPXfGQsqEAF8GnCdPSel7UUuvzXgcE2U0QolkxcVo3-9KIVd3zmLQ6HJPjwFqJF7RSwryIbFPFklvTpbrZzlORkLWk8nwB-1LUSlip_4PjZE2gKXe_iy23q5P8LfeoBWrH17tZAcGeB3U7g5C6I May 01 08:10:02 damien volumio[1450]: info: Spotify credentials grant success - running version from March 24, 2019 May 01 08:10:02 damien sudo[1737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 08:10:02 damien sudo[1733]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien sudo[1740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::volumioGetState May 01 08:10:02 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:02 damien sudo[1737]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien sudo[1740]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 08:10:02 damien systemd[1]: shairport-sync.service: Succeeded. May 01 08:10:02 damien systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien sudo[1733]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 08:10:02 damien systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 01 08:10:02 damien systemd[1]: shairport-sync.service: Succeeded. May 01 08:10:02 damien systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien sudo[1740]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien sudo[1737]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=debug msg="zeroconf server listening on port 35958" May 01 08:10:02 damien volumio[1450]: info: Asound.conf file unchanged, so no further update is needed May 01 08:10:02 damien volumio[1450]: info: Output device has changed, restarting MPD May 01 08:10:02 damien volumio[1450]: info: Output device has changed, restarting Shairport Sync May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:02 damien sudo[1768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 08:10:02 damien sudo[1768]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien sudo[1771]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 08:10:02 damien sudo[1768]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=debug msg="obtained new client token: AACv3Z+Jpi9XmO8klMkDKEJTL8u4r9fcoHgW1M51CriXjD6nsT5e+LQ/wp4ARAhLhYh0KEIOpY2EyZJCWMiPjiWV+rWMqJ7EqPowNgxaMh9i5DloDtfVTAIJ1vOo8txl3X+ZsNlbAiVfbOzPKNKheASMpcEeP6xWlF5hRnuUJrwHxI9QXwNSLjNc84nAKWck2ImeQpf6IelD+8nkao5rYcTqqQvjKI87uTmKmtp2u8cZib0WHvxsEJ0q9GWdxWg=" May 01 08:10:02 damien volumio[1450]: info: Preparing to generate the ALSA configuration file May 01 08:10:02 damien sudo[1771]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" May 01 08:10:02 damien volumio[1450]: info: Shairport-Sync Started May 01 08:10:02 damien volumio[1450]: Error adding Membership: Error: addMembership EINVAL May 01 08:10:02 damien volumio[1450]: info: Shairport-Sync Started May 01 08:10:02 damien volumio[1450]: info: Shairport-Sync Started May 01 08:10:02 damien volumio[1450]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 01 08:10:02 damien volumio[1450]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 01 08:10:02 damien volumio[1450]: info: Reading ALSA contributions from plugins. May 01 08:10:02 damien volumio[1450]: info: MPD Permissions set May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien go-librespot[1714]: time="2025-05-01T08:10:02+02:00" level=debug msg="completed keyexchange" May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 01 08:10:02 damien systemd[1]: mpd.service: Succeeded. May 01 08:10:02 damien systemd[1]: Stopped Music Player Daemon. May 01 08:10:02 damien volumio[1450]: info: Starting Shairport Sync May 01 08:10:02 damien systemd[1]: Starting Music Player Daemon... May 01 08:10:02 damien volumio[1450]: info: Asound.conf file unchanged, so no further update is needed May 01 08:10:02 damien volumio[1450]: info: Output device has changed, restarting MPD May 01 08:10:02 damien sudo[1795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 08:10:02 damien sudo[1795]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien volumio[1450]: info: Output device has changed, restarting Shairport Sync May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:02 damien systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 08:10:02 damien sudo[1804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 08:10:02 damien systemd[1]: shairport-sync.service: Succeeded. May 01 08:10:02 damien systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien sudo[1801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 08:10:02 damien systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien sudo[1795]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien sudo[1804]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien sudo[1793]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 01 08:10:02 damien sudo[1801]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien sudo[1793]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien sudo[1793]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien sudo[1801]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien volumio[1450]: info: Shairport-Sync Started May 01 08:10:02 damien volumio[1450]: info: MPD Permissions set May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:02 damien volumio[1450]: info: Starting Shairport Sync May 01 08:10:02 damien systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 01 08:10:02 damien systemd[1]: mpd.service: Succeeded. May 01 08:10:02 damien systemd[1]: Stopped Music Player Daemon. May 01 08:10:02 damien volumio[1450]: SPOTIFY: User informations: {"country":"FR","display_name":"Damock","email":"damienpierrelee@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1cu1z4j2f4w4r5m6jg8tlx0qq"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/1cu1z4j2f4w4r5m6jg8tlx0qq","id":"1cu1z4j2f4w4r5m6jg8tlx0qq","images":[],"product":"premium","type":"user","uri":"spotify:user:1cu1z4j2f4w4r5m6jg8tlx0qq"} May 01 08:10:02 damien systemd[1]: Starting Music Player Daemon... May 01 08:10:02 damien volumio[1450]: info: Spotify Successfully logged in May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 01 08:10:02 damien volumio[1450]: info: [1746079802801] CoreMusicLibrary::Adding element Spotify May 01 08:10:02 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 01 08:10:02 damien volumio[1450]: Cannot find translation for source YouTube Music May 01 08:10:02 damien volumio[1450]: Cannot find translation for source Podcast May 01 08:10:02 damien volumio[1450]: Cannot find translation for source Randomizer May 01 08:10:02 damien volumio[1450]: Cannot find translation for source Spotify May 01 08:10:02 damien sudo[1845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 08:10:02 damien sudo[1845]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 08:10:02 damien dhcpcd[1138]: wlan0: using IPv4LL address 169.254.113.43 May 01 08:10:02 damien dhcpcd[1138]: wlan0: adding route to 169.254.0.0/16 May 01 08:10:02 damien avahi-daemon[548]: Registering new address record for 169.254.113.43 on wlan0.IPv4. May 01 08:10:02 damien systemd[1]: shairport-sync.service: Succeeded. May 01 08:10:02 damien systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 08:10:02 damien sudo[1845]: pam_unix(sudo:session): session closed for user root May 01 08:10:02 damien sudo[1846]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 01 08:10:02 damien sudo[1846]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:02 damien volumio[1450]: info: Shairport-Sync Started May 01 08:10:02 damien sudo[1846]: pam_unix(sudo:session): session closed for user root May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="completed challenge" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="authenticated as 1cu1z4j2f4w4r5m6jg8tlx0qq" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="authenticated as 1cu1z4j2f4w4r5m6jg8tlx0qq" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="dealer connection opened" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="initializing zeroconf session, username: 1cu1z4j2f4w4r5m6jg8tlx0qq" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="autoplay enabled: false" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="received connection id: Yzg3ZjFiZDQtNmMzYS00MTA5LWEyZjktOTNiOTNkYzQ2NDE1K2RlYWxlcit0Y3A6Ly8wYWNhNDBhNS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArOTkzQkU3MERDQzExQzMyQ0U5OUQwQzcxRTVGREU1RUZEMDQ1M0QwREEzMzkxNjQyOEUwMEYwMDA2OEM0NkE1MQ==" May 01 08:10:03 damien go-librespot[1714]: time="2025-05-01T08:10:03+02:00" level=debug msg="put connect state because NEW_DEVICE" May 01 08:10:03 damien mpd[1882]: May 01 08:10 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 01 08:10:03 damien volumio[1450]: info: camilladsp spawned new process with pid 1889, instance 1, run: true May 01 08:10:03 damien volumio[1450]: info: camilladsp service started and running in background, instance 1 May 01 08:10:03 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 08:10:03 damien volumio[1450]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA May 01 08:10:03 damien volumio[1450]: info: FusionDsp loaded May 01 08:10:03 damien volumio[1450]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 08:10:03 damien volumio[1450]: info: FusionDsp - Reporting Fusion DSP Enabled May 01 08:10:03 damien volumio[1450]: info: Adding Signal Path Element [object Object] May 01 08:10:03 damien volumio[1450]: info: Adding fusiondspeq DSP Signal Path Element May 01 08:10:03 damien volumio[1450]: info: FusionDsp - ---- installed callbackRead May 01 08:10:03 damien volumio[1450]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 01 08:10:03 damien sudo[1899]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 01 08:10:03 damien sudo[1899]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:03 damien volumio[1450]: 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 01 08:10:03 damien systemd[1]: Started FusionDsp Daemon. May 01 08:10:03 damien volumio[1450]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 01 08:10:03 damien sudo[1899]: pam_unix(sudo:session): session closed for user root May 01 08:10:04 damien ntpd[1137]: Listen normally on 5 wlan0 169.254.113.43:123 May 01 08:10:04 damien ntpd[1137]: new interface(s) found: waking up resolver May 01 08:10:04 damien systemd[1]: Started Music Player Daemon. May 01 08:10:04 damien sudo[1804]: pam_unix(sudo:session): session closed for user root May 01 08:10:04 damien sudo[1647]: pam_unix(sudo:session): session closed for user root May 01 08:10:04 damien sudo[1626]: pam_unix(sudo:session): session closed for user root May 01 08:10:04 damien sudo[1771]: pam_unix(sudo:session): session closed for user root May 01 08:10:04 damien volumio[1450]: info: Completed starting Core Plugins May 01 08:10:04 damien volumio[1450]: info: ------------------------------------------- May 01 08:10:04 damien volumio[1450]: info: ----- MyVolumio plugins startup ---- May 01 08:10:04 damien volumio[1450]: info: ------------------------------------------- May 01 08:10:04 damien volumio[1450]: info: [MyVolumio PluginManager] Fetching plans data.... May 01 08:10:04 damien volumio[1450]: error: MPD error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: error: MPD error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: error: MPD error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: info: MPD running with PID1882 May 01 08:10:04 damien volumio[1450]: ,establishing connection May 01 08:10:04 damien volumio[1450]: error: MPD error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: error: The expression evaluated to a falsy value: May 01 08:10:04 damien volumio[1450]: assert.ok(self.idling) May 01 08:10:04 damien volumio[1450]: error: updateQueue error: null May 01 08:10:05 damien volumio[1450]: info: go-librespot daemon successfully initialized May 01 08:10:05 damien systemd[1]: systemd-timedated.service: Succeeded. May 01 08:10:06 damien sudo[1944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 01 08:10:06 damien sudo[1946]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 01 08:10:06 damien sudo[1944]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:06 damien sudo[1946]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:06 damien sudo[1944]: pam_unix(sudo:session): session closed for user root May 01 08:10:06 damien sudo[1952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 01 08:10:06 damien sudo[1946]: pam_unix(sudo:session): session closed for user root May 01 08:10:06 damien sudo[1952]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 08:10:06 damien systemd[1]: Started UPnP Renderer front-end to MPD. May 01 08:10:06 damien sudo[1952]: pam_unix(sudo:session): session closed for user root May 01 08:10:06 damien volumio[1450]: info: Upmpdcli Daemon Started May 01 08:10:06 damien volumio[1970]: Generating RSA private key, 4096 bit long modulus (2 primes) May 01 08:10:08 damien volumio[1450]: info: Initializing connection to go-librespot Websocket May 01 08:10:08 damien go-librespot[1714]: time="2025-05-01T08:10:08+02:00" level=debug msg="new websocket client" May 01 08:10:08 damien volumio[1450]: info: Connection to go-librespot Websocket established May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="handling transfer player command from 3047d019f036b87e530de25291f5dec6254de083" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:5orZL8SetQM1LR3pMXZMOa" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=trace msg="fetched new page 0 with 474 items (list: 474)" uri="spotify:playlist:5orZL8SetQM1LR3pMXZMOa" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="shuffled context with seed 11168441302961105343 (len: 474, keep: 437)" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="loading track (paused: false, position: 28696ms)" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=trace msg="emitting websocket event: will_play" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="selected format OGG_VORBIS_320 (96b4de208a2e4c79f2b68bdde9266c21261e1660)" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="requested aes key for file 96b4de208a2e4c79f2b68bdde9266c21261e1660, gid: 7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1361" May 01 08:10:10 damien volumio[1450]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7qiZfU4dY1lWllzX7mPBI3","play_origin":"playlist/ondemand"}} May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="fetched first chunk of 21, total size is 10758624 bytes" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:10 damien go-librespot[1714]: time="2025-05-01T08:10:10+02:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1124" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="fetched chunk 4/20, size: 524288" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="fetched chunk 5/20, size: 524288" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:11 damien volumio[1450]: info: Getting Spotify volume May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=trace msg="seek to 28696ms (diff: 146ms, samples: 1265493, bytes: 1290108)" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="created new output device" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=info msg="loaded track \"Shape of You\" (paused: false, position: 28696ms, duration: 233712ms, prefetched: false)" uri="spotify:track:7qiZfU4dY1lWllzX7mPBI3" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=trace msg="scheduling prefetch in 174s" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=trace msg="emitting websocket event: metadata" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=trace msg="emitting websocket event: active" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="sending successful reply for dealer request" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 08:10:11 damien go-librespot[1714]: time="2025-05-01T08:10:11+02:00" level=trace msg="emitting websocket event: playing" May 01 08:10:11 damien volumio[1450]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 01 08:10:11 damien volumio[1450]: info: FusionDsp - ---- read samplerate from file: 44100 May 01 08:10:11 damien volumio[1450]: info: camilladsp stopping service pid 1889... May 01 08:10:11 damien volumio[1450]: info: camilladsp service terminated, instance 1 May 01 08:10:11 damien volumio[1450]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 01 08:10:11 damien volumio[1450]: info: camilladsp service started and running in background, instance 1 May 01 08:10:11 damien volumio[1450]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7qiZfU4dY1lWllzX7mPBI3","name":"Shape of You","artist_names":["Ed Sheeran"],"album_name":"÷ (Deluxe)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ba5db46f4b838ef6027e6f96","position":28696,"duration":233712,"release_date":"year:2017 month:3 day:3","track_number":4,"disc_number":1}} May 01 08:10:11 damien volumio[1450]: SPOTIFY: received: {"type":"active","data":null} May 01 08:10:11 damien volumio[1450]: info: Aligning Spotify Volume to Volumio Volume May 01 08:10:11 damien volumio[1450]: info: CoreCommandRouter::volumioGetState May 01 08:10:11 damien volumio[1450]: info: CorePlayQueue::getTrack 0 May 01 08:10:11 damien volumio[1450]: info: Setting Spotify Volume from Volumio: 60 May 01 08:10:11 damien volumio[1450]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7qiZfU4dY1lWllzX7mPBI3","play_origin":"playlist/ondemand"}} May 01 08:10:11 damien volumio[1450]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 01 08:10:11 damien volumio[1450]: TypeError: Cannot read property 'service' of undefined May 01 08:10:11 damien volumio[1450]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) May 01 08:10:11 damien volumio[1450]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) May 01 08:10:11 damien volumio[1450]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) May 01 08:10:11 damien volumio[1450]: at WebSocket.emit (events.js:400:28) May 01 08:10:11 damien volumio[1450]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) May 01 08:10:11 damien volumio[1450]: at Receiver.emit (events.js:400:28) May 01 08:10:11 damien volumio[1450]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 01 08:10:11 damien volumio[1450]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 01 08:10:11 damien volumio[1450]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 01 08:10:11 damien volumio[1450]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 01 08:10:11 damien volumio[1450]: at writeOrBuffer (internal/streams/writable.js:358:12) May 01 08:10:11 damien volumio[1450]: at Receiver.Writable.write (internal/streams/writable.js:303:10) May 01 08:10:11 damien volumio[1450]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) May 01 08:10:11 damien volumio[1450]: at Socket.emit (events.js:400:28) May 01 08:10:11 damien volumio[1450]: at addChunk (internal/streams/readable.js:293:12) May 01 08:10:11 damien volumio[1450]: at readableAddChunk (internal/streams/readable.js:267:9) May 01 08:10:11 damien volumio[1450]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 01 08:10:11 damien volumio[1970]: ..........................................................................................................++++ May 01 08:10:11 damien sudo[2005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-01 08:09 May 01 08:10:11 damien sudo[2005]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:11:38 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="932fc3546f7cc8faa2b4d349036752dd"