-- Logs begin at Mon 2026-01-26 06:28:51 IST, end at Mon 2026-01-26 06:30:15 IST. -- Jan 26 06:29:00 rpi2 ntpd[654]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jan 26 06:29:00 rpi2 volumio-time-update[480]: volumio-time-update-util: Fetching time from Volumio... Jan 26 06:29:00 rpi2 volumio-time-update[480]: volumio-time-update-util: Date not found in response Jan 26 06:29:00 rpi2 volumio-time-update[480]: volumio-time-update-util: Retrying in 5 seconds... Jan 26 06:29:00 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:00] [info] asio async_connect error: system:111 (Connection refused) Jan 26 06:29:00 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:00] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 26 06:29:00 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:00] [error] handle_connect error: Underlying Transport Error Jan 26 06:29:00 rpi2 sudo[722]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:00 rpi2 wireless.js[510]: DHCP IP Jan 26 06:29:00 rpi2 wireless.js[510]: Start ap Jan 26 06:29:00 rpi2 wpa_supplicant[729]: Successfully initialized wpa_supplicant Jan 26 06:29:00 rpi2 sudo[730]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jan 26 06:29:00 rpi2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 06:29:00 rpi2 sudo[730]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:00 rpi2 dhcpcd[731]: dev: loaded udev Jan 26 06:29:00 rpi2 kernel: 8021q: 802.1Q VLAN Support v1.8 Jan 26 06:29:00 rpi2 dhcpcd[731]: wlan0: connected to Access Point `' Jan 26 06:29:00 rpi2 dhcpcd[731]: no interfaces have a carrier Jan 26 06:29:00 rpi2 dhcpcd[731]: forked to background, child pid 755 Jan 26 06:29:00 rpi2 dhcpcd[755]: wlan0: waiting for carrier Jan 26 06:29:00 rpi2 sudo[730]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:00 rpi2 mpd[677]: Jan 26 06:29 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 06:29:00 rpi2 systemd[1]: Started Music Player Daemon. Jan 26 06:29:00 rpi2 mpd_monitor.sh[494]: MPD Monitor Service: MPD restarted due to no mpc output. Jan 26 06:29:00 rpi2 bthelper[600]: Changing power off succeeded Jan 26 06:29:00 rpi2 bthelper[600]: [CHG] Controller D8:3A:DD:44:45:08 Class: 0x0000041c Jan 26 06:29:00 rpi2 bthelper[600]: Changing power on succeeded Jan 26 06:29:01 rpi2 wpa_supplicant[741]: wlan0: Trying to associate with SSID 'agagagag_e' Jan 26 06:29:01 rpi2 wpa_supplicant[741]: wlan0: Associated with 9a:aa:5f:eb:53:ea Jan 26 06:29:01 rpi2 wpa_supplicant[741]: wlan0: CTRL-EVENT-CONNECTED - Connection to 9a:aa:5f:eb:53:ea completed [id=0 id_str=] Jan 26 06:29:01 rpi2 dhcpcd[755]: wlan0: carrier acquired Jan 26 06:29:01 rpi2 wpa_supplicant[741]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 26 06:29:01 rpi2 dhcpcd[755]: wlan0: connected to Access Point `agagagag_e' Jan 26 06:29:01 rpi2 wpa_supplicant[741]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Jan 26 06:29:01 rpi2 dhcpcd[755]: DUID 00:01:00:01:2f:53:00:87:d8:3a:dd:44:45:06 Jan 26 06:29:01 rpi2 dhcpcd[755]: wlan0: IAID dd:44:45:06 Jan 26 06:29:01 rpi2 dhcpcd[755]: wlan0: adding address fe80::89c7:cf64:5fe6:e2b Jan 26 06:29:01 rpi2 dhcpcd[755]: ipv6_addaddr1: Permission denied Jan 26 06:29:01 rpi2 wireless.js[510]: trying... Jan 26 06:29:01 rpi2 sudo[767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 06:29:01 rpi2 sudo[767]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:01 rpi2 sudo[767]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:01 rpi2 dhcpcd[755]: wlan0: soliciting an IPv6 router Jan 26 06:29:02 rpi2 dhcpcd[755]: wlan0: soliciting a DHCP lease Jan 26 06:29:02 rpi2 dhcpcd[755]: wlan0: offered 192.168.1.191 from 192.168.1.1 Jan 26 06:29:02 rpi2 dhcpcd[755]: wlan0: probing address 192.168.1.191/24 Jan 26 06:29:02 rpi2 wireless.js[510]: trying... Jan 26 06:29:02 rpi2 sudo[770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 06:29:02 rpi2 sudo[770]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:02 rpi2 sudo[770]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:03 rpi2 wireless.js[510]: trying... Jan 26 06:29:03 rpi2 sudo[773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 06:29:03 rpi2 sudo[773]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:03 rpi2 sudo[773]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:04 rpi2 wireless.js[510]: trying... Jan 26 06:29:04 rpi2 sudo[776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 06:29:04 rpi2 sudo[776]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:04 rpi2 sudo[776]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:05 rpi2 volumio-time-update[480]: volumio-time-update-util: Fetching time from Volumio... Jan 26 06:29:05 rpi2 volumio-time-update[480]: volumio-time-update-util: Date not found in response Jan 26 06:29:05 rpi2 volumio-time-update[480]: volumio-time-update-util: Retrying in 5 seconds... Jan 26 06:29:05 rpi2 wireless.js[510]: trying... Jan 26 06:29:05 rpi2 sudo[784]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 06:29:05 rpi2 sudo[784]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:05 rpi2 sudo[784]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:06 rpi2 wireless.js[510]: trying... Jan 26 06:29:06 rpi2 sudo[787]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 06:29:06 rpi2 sudo[787]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:06 rpi2 sudo[787]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:07 rpi2 dhcpcd[755]: wlan0: leased 192.168.1.191 for 43200 seconds Jan 26 06:29:07 rpi2 avahi-daemon[504]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.191. Jan 26 06:29:07 rpi2 dhcpcd[755]: wlan0: adding route to 192.168.1.0/24 Jan 26 06:29:07 rpi2 dhcpcd[755]: wlan0: adding default route via 192.168.1.1 Jan 26 06:29:07 rpi2 avahi-daemon[504]: New relevant interface wlan0.IPv4 for mDNS. Jan 26 06:29:07 rpi2 avahi-daemon[504]: Registering new address record for 192.168.1.191 on wlan0.IPv4. Jan 26 06:29:07 rpi2 wireless.js[510]: trying... Jan 26 06:29:07 rpi2 sudo[810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 06:29:07 rpi2 sudo[810]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:07 rpi2 sudo[810]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:07 rpi2 wireless.js[510]: Connected to: ----agagagag_e Jan 26 06:29:07 rpi2 wireless.js[510]: ---- Jan 26 06:29:07 rpi2 sudo[813]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 06:29:07 rpi2 sudo[813]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:07 rpi2 sudo[813]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:07 rpi2 wireless.js[510]: ... joined AP, wlan0 IPv4 is 192.168.1.191, ipV6 is undefined Jan 26 06:29:07 rpi2 wireless.js[510]: It's done! AP Jan 26 06:29:07 rpi2 nmbd[623]: [2026/01/26 06:29:07.467922, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 26 06:29:07 rpi2 nmbd[623]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 26 06:29:07 rpi2 systemd[1]: Started Samba NMB Daemon. Jan 26 06:29:07 rpi2 systemd[1]: Starting Samba Winbind Daemon... Jan 26 06:29:07 rpi2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 06:29:07 rpi2 systemd[1]: Started Wireless Services. Jan 26 06:29:07 rpi2 systemd[1]: Started Volumio Backend Module. Jan 26 06:29:07 rpi2 systemd[1]: Started Volumio Cpu Tweaker. Jan 26 06:29:07 rpi2 volumio-cpu-tweak[821]: Setting RT Priority for mpd Jan 26 06:29:07 rpi2 volumio-cpu-tweak[821]: Setting MPD Affinity Jan 26 06:29:07 rpi2 volumio-cpu-tweak[821]: pid 677's current affinity mask: f Jan 26 06:29:07 rpi2 volumio-cpu-tweak[821]: pid 677's new affinity mask: 3 Jan 26 06:29:07 rpi2 volumio-cpu-tweak[821]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jan 26 06:29:07 rpi2 volumio-cpu-tweak[821]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jan 26 06:29:07 rpi2 systemd[1]: volumio_cpu_tweak.service: Succeeded. Jan 26 06:29:07 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:07] [info] asio async_connect error: system:111 (Connection refused) Jan 26 06:29:07 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:07] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 26 06:29:07 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:07] [error] handle_connect error: Underlying Transport Error Jan 26 06:29:07 rpi2 winbindd[818]: [2026/01/26 06:29:07.910655, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 26 06:29:07 rpi2 winbindd[818]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 26 06:29:07 rpi2 winbindd[818]: [2026/01/26 06:29:07.946645, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 26 06:29:07 rpi2 winbindd[818]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 26 06:29:07 rpi2 systemd[1]: Started Samba Winbind Daemon. Jan 26 06:29:08 rpi2 systemd[1]: Starting Samba SMB Daemon... Jan 26 06:29:08 rpi2 ntpd[654]: Listen normally on 3 wlan0 192.168.1.191:123 Jan 26 06:29:08 rpi2 ntpd[654]: new interface(s) found: waking up resolver Jan 26 06:29:08 rpi2 smbd[840]: [2026/01/26 06:29:08.659626, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 26 06:29:08 rpi2 smbd[840]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 26 06:29:08 rpi2 systemd[1]: Started Samba SMB Daemon. Jan 26 06:29:10 rpi2 volumio-time-update[480]: volumio-time-update-util: Fetching time from Volumio... Jan 26 06:29:10 rpi2 volumio-time-update[480]: volumio-time-update-util: Setting system time to: 2026-01-26 06:29:32 Jan 26 06:29:10 rpi2 sudo[861]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2026-01-26 06:29:32 Jan 26 06:29:10 rpi2 sudo[861]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:10 rpi2 dbus-daemon[484]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.10' (uid=0 pid=862 comm="timedatectl set-time 2026-01-26 06:29:32 ") Jan 26 06:29:10 rpi2 systemd[1]: Starting Time & Date Service... Jan 26 06:29:10 rpi2 volumio[820]: info: ------------------------------------------- Jan 26 06:29:10 rpi2 volumio[820]: info: ----- Volumio3 ---- Jan 26 06:29:10 rpi2 volumio[820]: info: ------------------------------------------- Jan 26 06:29:10 rpi2 volumio[820]: info: ----- System startup ---- Jan 26 06:29:10 rpi2 volumio[820]: info: ------------------------------------------- Jan 26 06:29:11 rpi2 dbus-daemon[484]: [system] Successfully activated service 'org.freedesktop.timedate1' Jan 26 06:29:11 rpi2 systemd[1]: Started Time & Date Service. Jan 26 06:29:32 rpi2 systemd-timedated[863]: Changed local time to Mon Jan 26 06:29:32 2026 Jan 26 06:29:32 rpi2 sudo[861]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:32 rpi2 volumio-time-update[480]: volumio-time-update-util: System time updated successfully. Jan 26 06:29:32 rpi2 systemd[1]: Started Volumio Time Update Utility. Jan 26 06:29:32 rpi2 systemd[1]: Reached target Multi-User System. Jan 26 06:29:32 rpi2 systemd[1]: Reached target Graphical Interface. Jan 26 06:29:32 rpi2 systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 26 06:29:32 rpi2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 26 06:29:32 rpi2 systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 26 06:29:32 rpi2 systemd[1]: Startup finished in 14.095s (kernel) + 21.874s (userspace) = 35.969s. Jan 26 06:29:33 rpi2 volumio[820]: info: MYVOLUMIO Environment detected Jan 26 06:29:33 rpi2 volumio[820]: info: Plugin folders cleanup Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning into folder /volumio/app/plugins/ Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category audio_interface Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category miscellanea Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category music_service Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category plugins.json Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category system_controller Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category user_interface Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning into folder /data/plugins/ Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category music_service Jan 26 06:29:33 rpi2 volumio[820]: info: Scanning category system_controller Jan 26 06:29:33 rpi2 volumio[820]: info: Plugin folders cleanup completed Jan 26 06:29:33 rpi2 volumio[820]: info: ------------------------------------------- Jan 26 06:29:33 rpi2 volumio[820]: info: ----- Core plugins startup ---- Jan 26 06:29:33 rpi2 volumio[820]: info: ------------------------------------------- Jan 26 06:29:33 rpi2 volumio[820]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 06:29:33 rpi2 volumio[820]: info: Adding plugin upnp to MyMusic Plugins Jan 26 06:29:33 rpi2 volumio[820]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 06:29:33 rpi2 volumio[820]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 06:29:33 rpi2 volumio[820]: info: Loading plugins from folder /data/plugins/ Jan 26 06:29:33 rpi2 volumio[820]: info: Loading plugin "system"... Jan 26 06:29:33 rpi2 volumio[820]: info: Loading plugin "appearance"... Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "network"... Jan 26 06:29:35 rpi2 volumio[820]: info: Refreshing Cached IP Addresses Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "services"... Jan 26 06:29:35 rpi2 sudo[874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 06:29:35 rpi2 sudo[872]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 06:29:35 rpi2 sudo[874]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:35 rpi2 sudo[872]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:35 rpi2 sudo[874]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "alsa_controller"... Jan 26 06:29:35 rpi2 sudo[881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 06:29:35 rpi2 sudo[881]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:35 rpi2 sudo[872]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:35 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "wizard"... Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "networkfs"... Jan 26 06:29:35 rpi2 volumio[820]: info: Starting Udev Watcher for removable devices Jan 26 06:29:35 rpi2 sudo[902]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=arun,password=a123run,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.111/m /mnt/NAS/dt3 Jan 26 06:29:35 rpi2 sudo[902]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:35 rpi2 volumio[820]: info: Ignoring mount for partition: boot Jan 26 06:29:35 rpi2 volumio[820]: info: Ignoring mount for partition: volumio Jan 26 06:29:35 rpi2 volumio[820]: info: Ignoring mount for partition: volumio_data Jan 26 06:29:35 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "volumio_command_line_client"... Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "upnp"... Jan 26 06:29:35 rpi2 volumio[820]: info: [1769389175820] Starting Upmpd Daemon Jan 26 06:29:35 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "my_music"... Jan 26 06:29:35 rpi2 volumio[820]: info: Loading plugin "mpd"... Jan 26 06:29:36 rpi2 kernel: Key type cifs.spnego registered Jan 26 06:29:36 rpi2 kernel: Key type cifs.idmap registered Jan 26 06:29:36 rpi2 kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jan 26 06:29:36 rpi2 kernel: CIFS: Attempting to mount //192.168.1.111/m Jan 26 06:29:36 rpi2 kernel: cryptd: max_cpu_qlen set to 1000 Jan 26 06:29:36 rpi2 sudo[881]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:36 rpi2 sudo[902]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:36 rpi2 volumio[820]: info: Loading plugin "upnp_browser"... Jan 26 06:29:37 rpi2 volumio[820]: info: Loading plugin "alarm-clock"... Jan 26 06:29:37 rpi2 volumio[820]: info: Loading plugin "airplay_emulation"... Jan 26 06:29:37 rpi2 volumio[820]: info: Starting Shairport Sync Jan 26 06:29:37 rpi2 volumio[820]: info: Loading plugin "last_100"... Jan 26 06:29:37 rpi2 volumio[820]: info: Loading plugin "webradio"... Jan 26 06:29:37 rpi2 volumio[820]: info: Loading plugin "i2s_dacs"... Jan 26 06:29:37 rpi2 volumio[820]: info: I2S DAC not set, start Auto-detection Jan 26 06:29:37 rpi2 volumio[820]: info: Loading plugin "volumiodiscovery"... Jan 26 06:29:37 rpi2 volumio[820]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 06:29:37 rpi2 volumio[820]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 06:29:37 rpi2 volumio[820]: *** WARNING *** For more information see Jan 26 06:29:37 rpi2 node[820]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 06:29:37 rpi2 volumio[820]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 06:29:37 rpi2 volumio[820]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 06:29:37 rpi2 volumio[820]: *** WARNING *** For more information see Jan 26 06:29:37 rpi2 node[820]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 06:29:37 rpi2 node[820]: *** WARNING *** For more information see Jan 26 06:29:37 rpi2 node[820]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 06:29:37 rpi2 node[820]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 06:29:37 rpi2 node[820]: *** WARNING *** For more information see Jan 26 06:29:37 rpi2 volumio[820]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 06:29:37 rpi2 volumio[820]: info: Discovery: Started advertising with name: rpi2 Jan 26 06:29:37 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 06:29:37 rpi2 volumio[820]: info: Loading plugin "spop"... Jan 26 06:29:38 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:38] [connect] Successful connection Jan 26 06:29:39 rpi2 volumio[820]: info: Loading plugin "autostart"... Jan 26 06:29:40 rpi2 volumio[820]: info: Applying required configuration parameters for plugin autostart Jan 26 06:29:40 rpi2 volumio[820]: info: AutoStart - onVolumioStart - read config.json Jan 26 06:29:40 rpi2 volumio[820]: info: Loading plugin "outputs"... Jan 26 06:29:40 rpi2 volumio[820]: info: Loading plugin "albumart"... Jan 26 06:29:40 rpi2 volumio[820]: info: Plugin example_plugin is not enabled Jan 26 06:29:40 rpi2 volumio[820]: info: Loading plugin "inputs"... Jan 26 06:29:40 rpi2 volumio[820]: info: Loading plugin "updater_comm"... Jan 26 06:29:40 rpi2 volumio[820]: info: Plugin mpdemulation is not enabled Jan 26 06:29:40 rpi2 volumio[820]: info: Loading plugin "rest_api"... Jan 26 06:29:40 rpi2 volumio[820]: info: Loading plugin "websocket"... Jan 26 06:29:40 rpi2 volumio[820]: info: Starting Socket.io Server version 2.3.0 Jan 26 06:29:40 rpi2 volumio[820]: info: Loading plugin "80s80s"... Jan 26 06:29:40 rpi2 volumio[820]: Forking 3 albumart workers Jan 26 06:29:41 rpi2 volumio[820]: info: Applying required configuration parameters for plugin 80s80s Jan 26 06:29:41 rpi2 volumio[820]: info: [1769389181280] [80s80s] API delay: 30 Jan 26 06:29:41 rpi2 volumio[820]: info: Loading plugin "radio_paradise"... Jan 26 06:29:41 rpi2 volumio[820]: info: Applying required configuration parameters for plugin radio_paradise Jan 26 06:29:41 rpi2 volumio[820]: info: [1769389181872] [RadioParadise] API delay: 5 Jan 26 06:29:41 rpi2 volumio[820]: info: Loading i18n strings for locale en Jan 26 06:29:41 rpi2 volumio[820]: Updating browse sources language Jan 26 06:29:41 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 06:29:42 rpi2 volumio[820]: Starting albumart workers Jan 26 06:29:42 rpi2 volumio[820]: Starting albumart workers Jan 26 06:29:42 rpi2 volumio[820]: Starting albumart workers Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::initPlayerControls Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 06:29:42 rpi2 volumio[820]: Express server listening on port 3000 Jan 26 06:29:42 rpi2 volumio[820]: [Metrics] WebUI: 11s 809.09ms Jan 26 06:29:42 rpi2 volumio[820]: info: CoreStateMachine::resetVolumioState Jan 26 06:29:42 rpi2 volumio[820]: info: CoreStateMachine::getcurrentVolume Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 06:29:42 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:42 rpi2 volumio[820]: info: Volumio Network Manager: Network status updated: 2 Jan 26 06:29:42 rpi2 volumio[820]: verbose: New Socket.io Connection to 192.168.1.191 from 192.168.1.111 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jan 26 06:29:42 rpi2 volumio[820]: verbose: New Socket.io Connection to 192.168.1.191 from 192.168.1.111 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Jan 26 06:29:42 rpi2 volumio-remote-updater[489]: [2026-01-26 06:29:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1769389178 101 Jan 26 06:29:42 rpi2 volumio[820]: 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: 3 Jan 26 06:29:42 rpi2 volumio[820]: verbose: New Socket.io Connection to 192.168.1.191 from 192.168.1.111 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jan 26 06:29:42 rpi2 volumio[820]: info: Reloading queue from file Jan 26 06:29:43 rpi2 volumio[820]: info: CoreStateMachine::setRepeat true single undefined Jan 26 06:29:43 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:29:43 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:29:43 rpi2 volumio[820]: info: CoreStateMachine::setRandom false Jan 26 06:29:43 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:29:43 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:29:43 rpi2 volumio[820]: info: Setting Device type: Raspberry PI Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioGetState Jan 26 06:29:43 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:43 rpi2 volumio[820]: info: VolumeController:: Volume=18 Mute =false Jan 26 06:29:43 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:29:43 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:29:43 rpi2 volumio[820]: info: CoreStateMachine::updateTrackBlock Jan 26 06:29:43 rpi2 volumio[820]: info: CorePlayQueue::getTrackBlock Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 06:29:43 rpi2 volumio[820]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 26 06:29:43 rpi2 volumio[820]: info: USB Boot Capable - System SBC Revision found in cpuinfo: 902120 Jan 26 06:29:43 rpi2 volumio[820]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 26 06:29:43 rpi2 volumio[820]: info: Listing playlists Jan 26 06:29:43 rpi2 volumio[820]: info: Discovery: adding 53517d56-7427-4f29-beeb-a50264b7ecd2 Jan 26 06:29:43 rpi2 volumio[820]: info: Discovery: Found device rpi2 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioGetState Jan 26 06:29:43 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:43 rpi2 volumio[820]: info: VolumeController:: Volume=18 Mute =false Jan 26 06:29:43 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:29:43 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:29:43 rpi2 volumio[820]: info: Completed loading Core Plugins Jan 26 06:29:43 rpi2 volumio[820]: info: Preparing to generate the ALSA configuration file Jan 26 06:29:43 rpi2 volumio[820]: info: Asound.conf file unchanged, so no further update is needed Jan 26 06:29:43 rpi2 volumio[820]: info: Output device has changed, restarting MPD Jan 26 06:29:43 rpi2 volumio[820]: info: Output device has changed, restarting Shairport Sync Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:43 rpi2 sudo[1010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 06:29:43 rpi2 sudo[1012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 06:29:43 rpi2 sudo[1012]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:43 rpi2 sudo[1010]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:43 rpi2 sudo[1010]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:43 rpi2 volumio[820]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 06:29:43 rpi2 systemd[1]: Stopping Music Player Daemon... Jan 26 06:29:43 rpi2 volumio[820]: info: ___________ START PLUGINS ___________ Jan 26 06:29:43 rpi2 volumio[820]: info: ControllerMpd::onStart: Initializing MPD Jan 26 06:29:43 rpi2 volumio[820]: info: Creating MPD Configuration file Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 06:29:43 rpi2 sudo[1019]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 06:29:43 rpi2 volumio[820]: info: [1769389183539] CoreMusicLibrary::Adding element Media Servers Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 06:29:43 rpi2 sudo[1019]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:43 rpi2 sudo[1019]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:43 rpi2 sudo[1021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 06:29:43 rpi2 sudo[1021]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:43 rpi2 volumio[820]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:43 rpi2 volumio[820]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 06:29:43 rpi2 volumio[820]: info: [1769389183713] CoreMusicLibrary::Adding element Last_100 Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 06:29:43 rpi2 volumio[820]: info: [1769389183717] CoreMusicLibrary::Adding element Webradio Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 06:29:43 rpi2 volumio[820]: info: Initializing BBC Radios Jan 26 06:29:43 rpi2 volumio[820]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:43 rpi2 systemd[1]: systemd-fsckd.service: Succeeded. Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:43 rpi2 volumio[820]: info: Creating Spotify config file Jan 26 06:29:43 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:43 rpi2 systemd[1]: mpd.service: Succeeded. Jan 26 06:29:43 rpi2 systemd[1]: Stopped Music Player Daemon. Jan 26 06:29:44 rpi2 systemd[1]: Starting Music Player Daemon... Jan 26 06:29:44 rpi2 volumio[820]: info: AutoStart - onStart Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 06:29:44 rpi2 volumio[820]: info: [1769389184037] CoreMusicLibrary::Adding element 80s80s Radio Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 06:29:44 rpi2 volumio[820]: Cannot find translation for source 80s80s Radio Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 06:29:44 rpi2 volumio[820]: info: [1769389184048] CoreMusicLibrary::Adding element Radio Paradise Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 06:29:44 rpi2 volumio[820]: Cannot find translation for source 80s80s Radio Jan 26 06:29:44 rpi2 volumio[820]: Cannot find translation for source Radio Paradise Jan 26 06:29:44 rpi2 volumio[820]: info: Volumio Calling Home Jan 26 06:29:44 rpi2 sudo[1040]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 06:29:44 rpi2 sudo[1040]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:44 rpi2 sudo[1040]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:44 rpi2 volumio[820]: info: MPD Permissions set Jan 26 06:29:44 rpi2 volumio[820]: info: MPD Permissions set Jan 26 06:29:44 rpi2 volumio[820]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 26 06:29:44 rpi2 volumio[820]: info: Spotify config file written Jan 26 06:29:44 rpi2 sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 06:29:44 rpi2 sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 systemd[1]: Started go-librespot Daemon. Jan 26 06:29:44 rpi2 sudo[1047]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:44 rpi2 go-librespot[1049]: go-librespot daemon starting... Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 06:29:44 rpi2 volumio[820]: info: No need to fix Spotify hosts Jan 26 06:29:44 rpi2 volumio[820]: info: Starting Shairport Sync Jan 26 06:29:44 rpi2 volumio[820]: info: Starting Shairport Sync Jan 26 06:29:44 rpi2 volumio[820]: info: Starting Shairport Sync Jan 26 06:29:44 rpi2 sudo[1060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 06:29:44 rpi2 volumio[820]: info: CoreCommandRouter::volumioGetState Jan 26 06:29:44 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:44 rpi2 sudo[1060]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:44 rpi2 sudo[1066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 06:29:44 rpi2 sudo[1066]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:44 rpi2 sudo[1068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 06:29:44 rpi2 sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:44 rpi2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 26 06:29:44 rpi2 systemd[1]: shairport-sync.service: Succeeded. Jan 26 06:29:44 rpi2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 26 06:29:44 rpi2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 26 06:29:44 rpi2 sudo[1060]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:44 rpi2 sudo[1066]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:44 rpi2 volumio[820]: info: Volumio called home Jan 26 06:29:44 rpi2 sudo[1068]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:44 rpi2 volumio[820]: info: Shairport-Sync Started Jan 26 06:29:44 rpi2 volumio[820]: Error adding Membership: Error: addMembership EINVAL Jan 26 06:29:44 rpi2 volumio[820]: info: Shairport-Sync Started Jan 26 06:29:44 rpi2 volumio[820]: info: Shairport-Sync Started Jan 26 06:29:45 rpi2 volumio[820]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 06:29:45 rpi2 volumio[820]: SPOTIFY: BQA0sWvkB8DJ_ahW59VNc76fvdPkigeuQ8TQOPDBahx_CMwk7zk-uw3dnCCHg51E_hWuHEBXw0M0uOnvQ9dcJeW2DcFi_6q8BVCiW5pHfh_h-5m1kaiTvnXby3NzNBhxq3phMRwNdkg_zrwMKaZrggwTIRcNeARRAnpBIFYUGDEx7xOcsZxkAjupLLIXykS6LFrUHstOAvBsp9XBh2e3dGn_3iv_1ahrEsxAWsGVp1OWgsKWW4bLCRAHAhH97FA5rDfgCbTtBRBLK1qcEFzYgzvKVqx8gbVErH5NhDaGXmAdftGPw42_Yjnh Jan 26 06:29:45 rpi2 volumio[820]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 06:29:45 rpi2 volumio[820]: info: New Spotify access token = BQA0sWvkB8DJ_ahW59VNc76fvdPkigeuQ8TQOPDBahx_CMwk7zk-uw3dnCCHg51E_hWuHEBXw0M0uOnvQ9dcJeW2DcFi_6q8BVCiW5pHfh_h-5m1kaiTvnXby3NzNBhxq3phMRwNdkg_zrwMKaZrggwTIRcNeARRAnpBIFYUGDEx7xOcsZxkAjupLLIXykS6LFrUHstOAvBsp9XBh2e3dGn_3iv_1ahrEsxAWsGVp1OWgsKWW4bLCRAHAhH97FA5rDfgCbTtBRBLK1qcEFzYgzvKVqx8gbVErH5NhDaGXmAdftGPw42_Yjnh Jan 26 06:29:45 rpi2 volumio[820]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 06:29:45 rpi2 go-librespot[1049]: time="2026-01-26T06:29:45+05:30" level=info msg="running go-librespot 0.2.0" Jan 26 06:29:45 rpi2 go-librespot[1049]: time="2026-01-26T06:29:45+05:30" level=debug msg="app state loaded" Jan 26 06:29:45 rpi2 go-librespot[1049]: time="2026-01-26T06:29:45+05:30" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 06:29:45 rpi2 volumio[820]: SPOTIFY: User informations: {"country":"IN","display_name":"Arun","email":null,"explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31vmfhaitxsbbdohcjx67fhdnfy4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31vmfhaitxsbbdohcjx67fhdnfy4","id":"31vmfhaitxsbbdohcjx67fhdnfy4","images":[],"product":"free","type":"user","uri":"spotify:user:31vmfhaitxsbbdohcjx67fhdnfy4"} Jan 26 06:29:45 rpi2 volumio[820]: info: Spotify Successfully logged in Jan 26 06:29:45 rpi2 volumio[820]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 06:29:45 rpi2 volumio[820]: info: [1769389185403] CoreMusicLibrary::Adding element Spotify Jan 26 06:29:45 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 06:29:45 rpi2 volumio[820]: Cannot find translation for source 80s80s Radio Jan 26 06:29:45 rpi2 volumio[820]: Cannot find translation for source Radio Paradise Jan 26 06:29:45 rpi2 volumio[820]: Cannot find translation for source Spotify Jan 26 06:29:45 rpi2 sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 06:29:45 rpi2 sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:45 rpi2 sudo[1095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 06:29:45 rpi2 sudo[1095]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:45 rpi2 sudo[1095]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:45 rpi2 sudo[1093]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:45 rpi2 go-librespot[1049]: time="2026-01-26T06:29:45+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 06:29:45 rpi2 go-librespot[1049]: time="2026-01-26T06:29:45+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 06:29:45 rpi2 go-librespot[1049]: time="2026-01-26T06:29:45+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 06:29:45 rpi2 go-librespot[1049]: time="2026-01-26T06:29:45+05:30" level=info msg="zeroconf server listening on port 37897" Jan 26 06:29:45 rpi2 sudo[1101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 06:29:45 rpi2 sudo[1101]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:46 rpi2 systemd[1]: Started UPnP Renderer front-end to MPD. Jan 26 06:29:46 rpi2 sudo[1101]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:46 rpi2 volumio[820]: info: Upmpdcli Daemon Started Jan 26 06:29:46 rpi2 go-librespot[1049]: time="2026-01-26T06:29:46+05:30" level=debug msg="obtained new client token: AABRS5YRv2m1T0r750iGdpPtWFEbNdOJPRBuSVZqPG8vP56yFu3VcGbqYdRStz07X2I7ujM6eXePT77chL4MBJGj6nv4efafXhFy1/WXVDv/6IKWL5pnvA85zqvdGx0U3Nlt5mFVRXmIeBaw7IcotzrXK249Ptlgx9IM5sVLyC3vHnvCc+RyDDwVX4C87GBdrQBcB3uNSrlNwTqoJZH/OOn7ia7QJ3ugohbC13VGTxSkjKl8chbuNTfdVSE=" Jan 26 06:29:46 rpi2 go-librespot[1049]: time="2026-01-26T06:29:46+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 06:29:46 rpi2 go-librespot[1049]: time="2026-01-26T06:29:46+05:30" level=debug msg="completed keyexchange" Jan 26 06:29:46 rpi2 go-librespot[1049]: time="2026-01-26T06:29:46+05:30" level=debug msg="completed challenge" Jan 26 06:29:46 rpi2 go-librespot[1049]: time="2026-01-26T06:29:46+05:30" level=info msg="authenticated AP as 31vmfhaitxsbbdohcjx67fhdnfy4" Jan 26 06:29:46 rpi2 go-librespot[1049]: time="2026-01-26T06:29:46+05:30" level=info msg="authenticated Login5 as 31vmfhaitxsbbdohcjx67fhdnfy4" Jan 26 06:29:46 rpi2 go-librespot[1049]: time="2026-01-26T06:29:46+05:30" level=debug msg="initializing zeroconf session, username: 31vmfhaitxsbbdohcjx67fhdnfy4" Jan 26 06:29:47 rpi2 mpd[1044]: Jan 26 06:29 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 06:29:47 rpi2 systemd[1]: Started Music Player Daemon. Jan 26 06:29:47 rpi2 sudo[1012]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:47 rpi2 sudo[1021]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="dealer connection opened" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=trace msg="starting accesspoint recv loop" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=trace msg="starting dealer recv loop" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=trace msg="received accesspoint ping" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="received connection id: YWM5ZTg0N2YtZWI0YS00NjQ3LThiY2ItMWJjYWQzZGQzYTZhK2RlYWxlcit0Y3A6Ly8wYWIxNThiYS5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArRTE1RDhGN0NCNUQzMzkwMzQ1MUYxQTMzNzkzQjY0MzRGQUQ4QjQ5MDAzNzlFQTJGNDEzMjk0RkE0RDNERkMwMQ==" Jan 26 06:29:47 rpi2 volumio[820]: info: Completed starting Core Plugins Jan 26 06:29:47 rpi2 volumio[820]: info: ------------------------------------------- Jan 26 06:29:47 rpi2 volumio[820]: info: ----- MyVolumio plugins startup ---- Jan 26 06:29:47 rpi2 volumio[820]: info: ------------------------------------------- Jan 26 06:29:47 rpi2 volumio[820]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=trace msg="received accesspoint pong ack" Jan 26 06:29:47 rpi2 volumio[1103]: Generating RSA private key, 4096 bit long modulus (2 primes) Jan 26 06:29:47 rpi2 volumio[820]: error: MPD error: The expression evaluated to a falsy value: Jan 26 06:29:47 rpi2 volumio[820]: assert.ok(self.idling) Jan 26 06:29:47 rpi2 volumio[820]: error: The expression evaluated to a falsy value: Jan 26 06:29:47 rpi2 volumio[820]: assert.ok(self.idling) Jan 26 06:29:47 rpi2 volumio[820]: error: updateQueue error: null Jan 26 06:29:47 rpi2 volumio[820]: info: MPD running with PID1044 Jan 26 06:29:47 rpi2 volumio[820]: ,establishing connection Jan 26 06:29:47 rpi2 volumio[820]: error: updateQueue error: null Jan 26 06:29:47 rpi2 go-librespot[1049]: time="2026-01-26T06:29:47+05:30" level=debug msg="put connect state because NEW_DEVICE" Jan 26 06:29:47 rpi2 volumio[820]: info: go-librespot daemon successfully initialized Jan 26 06:29:47 rpi2 systemd[1]: systemd-hostnamed.service: Succeeded. Jan 26 06:29:50 rpi2 volumio[820]: info: Initializing connection to go-librespot Websocket Jan 26 06:29:50 rpi2 go-librespot[1049]: time="2026-01-26T06:29:50+05:30" level=debug msg="new websocket client" Jan 26 06:29:50 rpi2 volumio[820]: info: Connection to go-librespot Websocket established Jan 26 06:29:52 rpi2 volumio[820]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 06:29:53 rpi2 volumio[820]: info: Getting Spotify volume Jan 26 06:29:53 rpi2 volumio[820]: info: Spotify volume: 100 Jan 26 06:29:53 rpi2 volumio[820]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 26 06:29:53 rpi2 volumio[820]: info: CoreCommandRouter::volumioGetState Jan 26 06:29:53 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:53 rpi2 volumio[820]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Jan 26 06:29:53 rpi2 volumio[820]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 06:29:53 rpi2 volumio[820]: SPOTIFY: VOLUMIO VOLUME 18 Jan 26 06:29:53 rpi2 volumio[820]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 26 06:29:53 rpi2 volumio[820]: info: Setting Spotify Volume from Volumio: 18 Jan 26 06:29:54 rpi2 volumio[820]: info: AutoStart - Plugin is starting Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::volumioGetQueue Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::getQueue Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getQueue Jan 26 06:29:54 rpi2 volumio[820]: info: AutoStart - start playing Jan 26 06:29:54 rpi2 volumio[820]: info: AutoStart - start playing with no specific position Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::volumioPlay Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::play index 0 Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::stop Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::play index undefined Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::startPlaybackTimer Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: [1769389194040] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/web/mp3-192/volumio Jan 26 06:29:54 rpi2 volumio[820]: info: [1769389194041] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=62&count=2 Jan 26 06:29:54 rpi2 volumio[820]: info: [1769389194459] [80s80s] received new event containing 2 songs. Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand stop Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand stop took 3 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand clear Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:54 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand clear took 4 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand consume 1 Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:54 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:54 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:54 rpi2 volumio[820]: error: updateQueue error: null Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces state update: options Jan 26 06:29:54 rpi2 volumio[820]: error: updateQueue error: null Jan 26 06:29:54 rpi2 volumio[820]: error: updateQueue error: null Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 18ms Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand consume 1 took 14 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 15ms Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 13ms Jan 26 06:29:54 rpi2 volumio[820]: info: [1769389194493] [80s80s] adding url: http://streams.80s80s.de/web/mp3-192/volumio Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces state update: options Jan 26 06:29:54 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces state update: options Jan 26 06:29:54 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:54 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand status took 17 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" took 13 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand status took 10 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand status took 7 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand play Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:54 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:54 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:29:54 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:29:54 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 65ms Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 67ms Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 68ms Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:54 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:54 rpi2 volumio[820]: info: Jan 26 06:29:54 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:54 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 78ms Jan 26 06:29:54 rpi2 volumio[820]: info: sendMpdCommand play took 65 milliseconds Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 10ms Jan 26 06:29:54 rpi2 volumio[820]: info: ------------------------------ 8ms Jan 26 06:29:54 rpi2 volumio[820]: info: [1769389194585] [80s80s] Pushing the next song state: Rockwell - Somebody's Watching Me Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:29:54 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:54 rpi2 volumio[820]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music114/v4/3e/e3/ca/3ee3ca6a-a2ea-712e-4399-e94fc29f2655/source/600x600bb.jpg","name":"Rockwell - Somebody's Watching Me","title":"Somebody's Watching Me","artist":"80s80s Real 80s Radio","album":"","streaming":true,"disableUiControls":true,"duration":"214","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jan 26 06:29:54 rpi2 volumio[820]: verbose: CURRENT POSITION 0 Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::syncState stateService play Jan 26 06:29:54 rpi2 volumio[820]: info: CoreStateMachine::syncState currentStatus stop Jan 26 06:29:54 rpi2 volumio[820]: info: [1769389194593] [80s80s] PlayNextTrack API delay: 30 Jan 26 06:29:54 rpi2 volumio[820]: info: [1769389194616] [80s80s] Setting timer to: 16407 milliseconds. Jan 26 06:29:54 rpi2 volumio[820]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Jan 26 06:29:54 rpi2 volumio[820]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Jan 26 06:29:54 rpi2 volumio[820]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Jan 26 06:29:55 rpi2 volumio[820]: SPOTIFY: SETTING SPOTIFY VOLUME 18 Jan 26 06:29:55 rpi2 volumio[820]: info: Sending Spotify command with payload to local API: /player/volume Jan 26 06:29:55 rpi2 go-librespot[1049]: time="2026-01-26T06:29:55+05:30" level=debug msg="update volume to 11796/65535" Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 06:29:55 rpi2 volumio[820]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 06:29:55 rpi2 volumio[820]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 06:29:55 rpi2 volumio[820]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 06:29:55 rpi2 volumio[820]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 06:29:55 rpi2 volumio[820]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 06:29:55 rpi2 volumio[820]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 06:29:55 rpi2 volumio[820]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 06:29:55 rpi2 volumio[820]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 06:29:56 rpi2 go-librespot[1049]: time="2026-01-26T06:29:56+05:30" level=debug msg="put connect state because VOLUME_CHANGED" Jan 26 06:29:56 rpi2 go-librespot[1049]: time="2026-01-26T06:29:56+05:30" level=trace msg="emitting websocket event: volume" Jan 26 06:29:57 rpi2 volumio[820]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 06:29:57 rpi2 volumio[820]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 06:29:57 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:57 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:57 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:29:57 rpi2 volumio[820]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 06:29:57 rpi2 volumio[820]: info: MyVolumio login type: Token Jan 26 06:29:57 rpi2 volumio[820]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 06:29:57 rpi2 volumio[820]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 06:29:59 rpi2 volumio[820]: info: Starting Streaming Service Transparent Proxy Jan 26 06:29:59 rpi2 volumio[820]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 06:29:59 rpi2 volumio[820]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 06:29:59 rpi2 volumio[820]: info: Streaming services startup Jan 26 06:29:59 rpi2 volumio[820]: info: Starting Streaming Daemon Jan 26 06:29:59 rpi2 volumio[820]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 06:29:59 rpi2 sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 06:29:59 rpi2 sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:29:59 rpi2 volumio[820]: SPOTIFY: received: {"type":"volume","data":{"value":18,"max":100}} Jan 26 06:29:59 rpi2 volumio[820]: SPOTIFY: RECEIVED SPOTIFY VOLUME 18 Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces state update: player Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces state update: player Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces state update: player Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:59 rpi2 sudo[1160]: pam_unix(sudo:session): session closed for user root Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:59 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces state update: player Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand status took 52 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand status took 49 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand status took 47 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:59 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces state update: player Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces system playlist update Jan 26 06:29:59 rpi2 volumio[820]: info: Ignoring MPD Status Update Jan 26 06:29:59 rpi2 volumio[820]: info: Jan 26 06:29:59 rpi2 volumio[820]: ---------------------------- MPD announces state update: player Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::getState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand status Jan 26 06:29:59 rpi2 volumio[820]: Upnp client error: Error: This socket has been ended by the other party Jan 26 06:29:59 rpi2 volumio[820]: error: Cannot start Volumio Streaming Daemon Jan 26 06:29:59 rpi2 volumio[820]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 06:29:59 rpi2 volumio[820]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 06:29:59 rpi2 volumio[820]: info: ------------------------------ 38ms Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand status took 36 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand playlistinfo took 26 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand playlistinfo took 26 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand playlistinfo took 25 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: info: ------------------------------ 24ms Jan 26 06:29:59 rpi2 volumio[820]: info: sendMpdCommand status took 22 milliseconds Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseTrackInfo Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseTrackInfo Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseTrackInfo Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:29:59 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:29:59 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:29:59 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:59 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:29:59 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:29:59 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:59 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:29:59 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:29:59 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:29:59 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:29:59 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:29:59 rpi2 volumio[820]: info: ------------------------------ 106ms Jan 26 06:29:59 rpi2 volumio[820]: info: ------------------------------ 103ms Jan 26 06:29:59 rpi2 volumio[820]: info: ------------------------------ 100ms Jan 26 06:30:00 rpi2 volumio[820]: info: ------------------------------ 43ms Jan 26 06:30:00 rpi2 volumio[820]: info: sendMpdCommand status took 41 milliseconds Jan 26 06:30:00 rpi2 volumio[820]: info: sendMpdCommand playlistinfo took 22 milliseconds Jan 26 06:30:00 rpi2 volumio[820]: info: sendMpdCommand playlistinfo took 18 milliseconds Jan 26 06:30:00 rpi2 volumio[820]: verbose: ControllerMpd::parseState Jan 26 06:30:00 rpi2 volumio[820]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 06:30:00 rpi2 volumio[820]: verbose: ControllerMpd::parseTrackInfo Jan 26 06:30:00 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:30:00 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:30:00 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:00 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:30:00 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:30:00 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:30:00 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:00 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:30:00 rpi2 volumio[820]: info: ------------------------------ 71ms Jan 26 06:30:00 rpi2 volumio[820]: info: ------------------------------ 54ms Jan 26 06:30:00 rpi2 volumio[820]: info: sendMpdCommand playlistinfo took 27 milliseconds Jan 26 06:30:00 rpi2 volumio[820]: verbose: ControllerMpd::parseTrackInfo Jan 26 06:30:00 rpi2 volumio[820]: info: ControllerMpd::pushState Jan 26 06:30:00 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:30:00 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:00 rpi2 volumio[820]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 26 06:30:00 rpi2 volumio[820]: info: ------------------------------ 75ms Jan 26 06:30:00 rpi2 volumio[820]: error: MyVolumio Custom Token format not valid, refreshing it Jan 26 06:30:01 rpi2 volumio[820]: STREAMING PROXY: Starting server on port 3245 Jan 26 06:30:01 rpi2 volumio[820]: Node JS runtime: 14 Jan 26 06:30:01 rpi2 volumio[820]: info: MyVolumio login type: Token Jan 26 06:30:02 rpi2 systemd[1]: systemd-timedated.service: Succeeded. Jan 26 06:30:02 rpi2 volumio[820]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 06:30:03 rpi2 volumio[820]: info: MyVolumio token set successfully Jan 26 06:30:03 rpi2 volumio[820]: info: MYVOLUMIO: Adding device Jan 26 06:30:03 rpi2 volumio[820]: info: MYVOLUMIO: Evaluating Server Jan 26 06:30:04 rpi2 volumio[820]: info: MyVolumio status changed Jan 26 06:30:04 rpi2 volumio[820]: info: Streaming services startup Jan 26 06:30:04 rpi2 volumio[820]: info: Starting Streaming Daemon Jan 26 06:30:04 rpi2 volumio[820]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 06:30:04 rpi2 volumio[820]: info: Removing audio output: Jan 26 06:30:04 rpi2 volumio[820]: info: Stoppping Tunnel 1 Jan 26 06:30:04 rpi2 sudo[1203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 06:30:04 rpi2 sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 26 06:30:04 rpi2 sudo[1203]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:30:04 rpi2 sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 06:30:04 rpi2 sudo[1203]: pam_unix(sudo:session): session closed for user root Jan 26 06:30:04 rpi2 volumio[820]: error: Cannot start Volumio Streaming Daemon Jan 26 06:30:04 rpi2 volumio[820]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 06:30:04 rpi2 volumio[820]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 06:30:04 rpi2 sudo[1205]: pam_unix(sudo:session): session closed for user root Jan 26 06:30:04 rpi2 volumio[820]: info: Remote SSH Stopped Jan 26 06:30:04 rpi2 volumio[820]: info: Setting Geolocation for MyVolumio to as2 Jan 26 06:30:04 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:04 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:04 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:04 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:05 rpi2 volumio[820]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 26 06:30:05 rpi2 volumio[820]: info: Updating MyVolumio device info Jan 26 06:30:05 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:05 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:05 rpi2 volumio[1103]: ..............................................................................................................++++ Jan 26 06:30:06 rpi2 volumio[820]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 26 06:30:09 rpi2 volumio[820]: info: MYVOLUMIO: Adding device Jan 26 06:30:09 rpi2 volumio[820]: info: MYVOLUMIO: Evaluating Server Jan 26 06:30:10 rpi2 volumio[820]: info: Setting Geolocation for MyVolumio to as2 Jan 26 06:30:10 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:10 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:10 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:10 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:10 rpi2 volumio[820]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 26 06:30:11 rpi2 volumio[820]: info: [1769389211026] [80s80s] Pushing the next song state Rockwell - Somebody's Watching Me and getting next track. Jan 26 06:30:11 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::servicePushState Jan 26 06:30:11 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:11 rpi2 volumio[820]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music114/v4/3e/e3/ca/3ee3ca6a-a2ea-712e-4399-e94fc29f2655/source/600x600bb.jpg","name":"Rockwell - Somebody's Watching Me","title":"Somebody's Watching Me","artist":"80s80s Real 80s Radio","album":"","streaming":true,"disableUiControls":true,"duration":"214","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jan 26 06:30:11 rpi2 volumio[820]: verbose: CURRENT POSITION 0 Jan 26 06:30:11 rpi2 volumio[820]: info: CoreStateMachine::syncState stateService play Jan 26 06:30:11 rpi2 volumio[820]: info: CoreStateMachine::syncState currentStatus play Jan 26 06:30:11 rpi2 volumio[820]: info: Received an update from plugin. extracting info from payload Jan 26 06:30:11 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:30:11 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:30:11 rpi2 volumio[820]: info: CoreStateMachine::pushState Jan 26 06:30:11 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::volumioPushState Jan 26 06:30:11 rpi2 volumio[820]: info: [1769389211061] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=62&count=1 Jan 26 06:30:11 rpi2 volumio[820]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Jan 26 06:30:11 rpi2 volumio[820]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Jan 26 06:30:11 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:11 rpi2 volumio[820]: info: CorePlayQueue::getTrack 1 Jan 26 06:30:11 rpi2 volumio[820]: info: Updating MyVolumio device info Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:11 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:12 rpi2 volumio[820]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 26 06:30:12 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 26 06:30:12 rpi2 volumio[820]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 26 06:30:12 rpi2 volumio[820]: info: CoreCommandRouter::volumioGetState Jan 26 06:30:12 rpi2 volumio[820]: info: CorePlayQueue::getTrack 0 Jan 26 06:30:14 rpi2 volumio[820]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jan 26 06:30:14 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:14 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 06:30:14 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 06:30:14 rpi2 volumio[820]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 26 06:30:14 rpi2 volumio[820]: info: [1769389214264] [80s80s] Failed to query api, status code: 503 Jan 26 06:30:14 rpi2 volumio[820]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 06:30:14 rpi2 volumio[820]: Error: ENOENT: no such file or directory, open '/data/plugins/music_service/80s80s/fake-data.json' Jan 26 06:30:14 rpi2 volumio[820]: at Object.openSync (fs.js:476:3) Jan 26 06:30:14 rpi2 volumio[820]: at Object.readFileSync (fs.js:377:35) Jan 26 06:30:14 rpi2 volumio[820]: at ClientRequest. (/data/plugins/music_service/80s80s/index.js:485:23) Jan 26 06:30:14 rpi2 volumio[820]: at Object.onceWrapper (events.js:422:26) Jan 26 06:30:14 rpi2 volumio[820]: at ClientRequest.emit (events.js:315:20) Jan 26 06:30:14 rpi2 volumio[820]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27) Jan 26 06:30:14 rpi2 volumio[820]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17) Jan 26 06:30:14 rpi2 volumio[820]: at Socket.socketOnData (_http_client.js:509:22) Jan 26 06:30:14 rpi2 volumio[820]: at Socket.emit (events.js:315:20) Jan 26 06:30:14 rpi2 volumio[820]: at addChunk (internal/streams/readable.js:309:12) Jan 26 06:30:14 rpi2 volumio[820]: at readableAddChunk (internal/streams/readable.js:284:9) Jan 26 06:30:14 rpi2 volumio[820]: at Socket.Readable.push (internal/streams/readable.js:223:10) Jan 26 06:30:14 rpi2 volumio[820]: at TCP.onStreamRead (internal/stream_base_commons.js:188:23) { Jan 26 06:30:14 rpi2 volumio[820]: errno: -2, Jan 26 06:30:14 rpi2 volumio[820]: syscall: 'open', Jan 26 06:30:14 rpi2 volumio[820]: code: 'ENOENT', Jan 26 06:30:14 rpi2 volumio[820]: path: '/data/plugins/music_service/80s80s/fake-data.json' Jan 26 06:30:14 rpi2 volumio[820]: } Jan 26 06:30:14 rpi2 volumio[820]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 06:30:15 rpi2 sudo[1272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-26 06:29 Jan 26 06:30:15 rpi2 sudo[1272]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"