-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2025-06-24 17:42:45 CEST. -- Jun 24 17:41:00 hificine wireless.js[591]: Cleaning previous... Jun 24 17:41:00 hificine ntpd[758]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 24 17:41:00 hificine sudo[822]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 24 17:41:00 hificine sudo[822]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:00 hificine sudo[822]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:00 hificine sudo[824]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 24 17:41:00 hificine sudo[824]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:00 hificine sudo[824]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:00 hificine systemd[1]: systemd-rfkill.service: Succeeded. Jun 24 17:41:00 hificine wireless.js[591]: Stopped aP Jun 24 17:41:00 hificine sudo[831]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 24 17:41:00 hificine sudo[831]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:00 hificine sudo[831]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:00 hificine kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 24 17:41:00 hificine sudo[833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Jun 24 17:41:00 hificine sudo[833]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:00 hificine sudo[833]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:00 hificine sudo[840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 24 17:41:00 hificine sudo[840]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:00 hificine sudo[840]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:00 hificine sudo[842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Jun 24 17:41:00 hificine sudo[842]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:01 hificine ntpd[758]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 24 17:41:01 hificine sudo[842]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:01 hificine wireless.js[591]: Start wireless flow Jun 24 17:41:01 hificine wireless.js[591]: Stopped hotspot (if there).. Jun 24 17:41:01 hificine sudo[847]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 24 17:41:01 hificine sudo[847]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:01 hificine sudo[847]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:01 hificine sudo[849]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 24 17:41:01 hificine sudo[849]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:02 hificine ntpd[758]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 24 17:41:02 hificine sudo[849]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:02 hificine wireless.js[591]: DHCP IP Jun 24 17:41:02 hificine wireless.js[591]: Start ap Jun 24 17:41:02 hificine wpa_supplicant[851]: Successfully initialized wpa_supplicant Jun 24 17:41:02 hificine sudo[852]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jun 24 17:41:02 hificine sudo[852]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:02 hificine dhcpcd[853]: dev: loaded udev Jun 24 17:41:02 hificine kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 24 17:41:02 hificine dhcpcd-run-hooks[871]: wlan0: starting wpa_supplicant Jun 24 17:41:02 hificine mpd[810]: Jun 24 17:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 24 17:41:02 hificine systemd[1]: Started Music Player Daemon. Jun 24 17:41:02 hificine mpd_monitor.sh[612]: MPD Monitor Service: MPD restarted due to no mpc output. Jun 24 17:41:02 hificine volumio-remote-updater[588]: [2025-06-24 17:41:02] [info] asio async_connect error: system:111 (Connection refused) Jun 24 17:41:02 hificine volumio-remote-updater[588]: [2025-06-24 17:41:02] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 24 17:41:02 hificine volumio-remote-updater[588]: [2025-06-24 17:41:02] [error] handle_connect error: Underlying Transport Error Jun 24 17:41:02 hificine dhcpcd-run-hooks[879]: wlan0: failed to start wpa_supplicant Jun 24 17:41:02 hificine dhcpcd-run-hooks[880]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Jun 24 17:41:02 hificine dhcpcd[853]: wlan0: connected to Access Point `' Jun 24 17:41:02 hificine dhcpcd[853]: no interfaces have a carrier Jun 24 17:41:02 hificine dhcpcd[853]: forked to background, child pid 890 Jun 24 17:41:02 hificine dhcpcd[890]: eth0: waiting for carrier Jun 24 17:41:02 hificine dhcpcd[890]: wlan0: waiting for carrier Jun 24 17:41:02 hificine sudo[852]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:02 hificine volumio-time-update[593]: volumio-time-update-util: Fetching time from Volumio... Jun 24 17:41:02 hificine volumio-time-update[593]: volumio-time-update-util: Date not found in response Jun 24 17:41:02 hificine volumio-time-update[593]: volumio-time-update-util: Retrying in 5 seconds... Jun 24 17:41:02 hificine bthelper[714]: Changing power off succeeded Jun 24 17:41:02 hificine wpa_supplicant[875]: wlan0: Trying to associate with SSID 'david' Jun 24 17:41:02 hificine bthelper[714]: [CHG] Controller B8:27:EB:FF:5D:71 Class: 0x0000041c Jun 24 17:41:02 hificine bthelper[714]: Changing power on succeeded Jun 24 17:41:02 hificine dhcpcd[890]: wlan0: carrier acquired Jun 24 17:41:02 hificine dhcpcd[890]: wlan0: connected to Access Point `david' Jun 24 17:41:02 hificine wpa_supplicant[875]: wlan0: Associated with 8c:97:ea:e0:46:f8 Jun 24 17:41:02 hificine wpa_supplicant[875]: wlan0: CTRL-EVENT-CONNECTED - Connection to 8c:97:ea:e0:46:f8 completed [id=0 id_str=] Jun 24 17:41:02 hificine wpa_supplicant[875]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 24 17:41:02 hificine dhcpcd[890]: DUID 00:01:00:01:2f:db:04:a3:b8:27:eb:55:f7:db Jun 24 17:41:02 hificine dhcpcd[890]: wlan0: IAID eb:00:a2:8e Jun 24 17:41:02 hificine dhcpcd[890]: wlan0: adding address fe80::3a5f:81a7:429:e8b Jun 24 17:41:02 hificine dhcpcd[890]: ipv6_addaddr1: Permission denied Jun 24 17:41:02 hificine dhcpcd[890]: wlan0: carrier lost Jun 24 17:41:03 hificine dhcpcd[890]: wlan0: carrier acquired Jun 24 17:41:03 hificine dhcpcd[890]: wlan0: IAID eb:00:a2:8e Jun 24 17:41:03 hificine wireless.js[591]: trying... Jun 24 17:41:03 hificine sudo[916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:03 hificine sudo[916]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:03 hificine sudo[916]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:03 hificine dhcpcd[890]: wlan0: soliciting an IPv6 router Jun 24 17:41:03 hificine dhcpcd[890]: wlan0: rebinding lease of 192.168.1.160 Jun 24 17:41:04 hificine wireless.js[591]: trying... Jun 24 17:41:04 hificine sudo[919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:04 hificine sudo[919]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:04 hificine sudo[919]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:05 hificine wireless.js[591]: trying... Jun 24 17:41:05 hificine sudo[922]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:05 hificine sudo[922]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:05 hificine sudo[922]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:06 hificine wireless.js[591]: trying... Jun 24 17:41:06 hificine sudo[925]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:06 hificine sudo[925]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:06 hificine sudo[925]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:07 hificine wireless.js[591]: trying... Jun 24 17:41:07 hificine sudo[928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:07 hificine sudo[928]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:07 hificine sudo[928]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:07 hificine dhcpcd[890]: wlan0: probing address 192.168.1.160/24 Jun 24 17:41:07 hificine volumio-time-update[593]: volumio-time-update-util: Fetching time from Volumio... Jun 24 17:41:07 hificine volumio-time-update[593]: volumio-time-update-util: Date not found in response Jun 24 17:41:07 hificine volumio-time-update[593]: volumio-time-update-util: Retrying in 5 seconds... Jun 24 17:41:08 hificine wireless.js[591]: trying... Jun 24 17:41:08 hificine sudo[936]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:08 hificine sudo[936]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:08 hificine sudo[936]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:09 hificine wireless.js[591]: trying... Jun 24 17:41:09 hificine sudo[939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:09 hificine sudo[939]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:09 hificine sudo[939]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:10 hificine volumio-remote-updater[588]: [2025-06-24 17:41:10] [info] asio async_connect error: system:111 (Connection refused) Jun 24 17:41:10 hificine volumio-remote-updater[588]: [2025-06-24 17:41:10] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 24 17:41:10 hificine volumio-remote-updater[588]: [2025-06-24 17:41:10] [error] handle_connect error: Underlying Transport Error Jun 24 17:41:10 hificine wireless.js[591]: trying... Jun 24 17:41:10 hificine sudo[942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:10 hificine sudo[942]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:10 hificine sudo[942]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:11 hificine wireless.js[591]: trying... Jun 24 17:41:11 hificine sudo[945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:11 hificine sudo[945]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:11 hificine sudo[945]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:12 hificine wireless.js[591]: trying... Jun 24 17:41:12 hificine sudo[948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:12 hificine sudo[948]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:12 hificine sudo[948]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:12 hificine dhcpcd[890]: wlan0: leased 192.168.1.160 for 43200 seconds Jun 24 17:41:12 hificine avahi-daemon[605]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.160. Jun 24 17:41:12 hificine avahi-daemon[605]: New relevant interface wlan0.IPv4 for mDNS. Jun 24 17:41:12 hificine avahi-daemon[605]: Registering new address record for 192.168.1.160 on wlan0.IPv4. Jun 24 17:41:12 hificine dhcpcd[890]: wlan0: adding route to 192.168.1.0/24 Jun 24 17:41:12 hificine dhcpcd[890]: wlan0: adding default route via 192.168.1.254 Jun 24 17:41:12 hificine volumio-time-update[593]: volumio-time-update-util: Fetching time from Volumio... Jun 24 17:41:12 hificine volumio-time-update[593]: volumio-time-update-util: Setting system time to: 2025-06-24 17:41:36 Jun 24 17:41:12 hificine sudo[975]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-06-24 17:41:36 Jun 24 17:41:12 hificine sudo[975]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:12 hificine dbus-daemon[607]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=976 comm="timedatectl set-time 2025-06-24 17:41:36 ") Jun 24 17:41:12 hificine systemd[1]: Starting Time & Date Service... Jun 24 17:41:13 hificine dbus-daemon[607]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 24 17:41:13 hificine systemd[1]: Started Time & Date Service. Jun 24 17:41:36 hificine systemd-timedated[977]: Changed local time to Tue Jun 24 17:41:36 2025 Jun 24 17:41:36 hificine sudo[975]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:36 hificine volumio-time-update[593]: volumio-time-update-util: System time updated successfully. Jun 24 17:41:36 hificine systemd[1]: Started Volumio Time Update Utility. Jun 24 17:41:36 hificine wireless.js[591]: trying... Jun 24 17:41:36 hificine sudo[979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 24 17:41:36 hificine sudo[979]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:36 hificine sudo[979]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:36 hificine wireless.js[591]: Connected to: ----david Jun 24 17:41:36 hificine wireless.js[591]: ---- Jun 24 17:41:36 hificine sudo[982]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 24 17:41:36 hificine sudo[982]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:36 hificine sudo[982]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:36 hificine wireless.js[591]: ... joined AP, wlan0 IPv4 is 192.168.1.160, ipV6 is undefined Jun 24 17:41:36 hificine wireless.js[591]: It's done! AP Jun 24 17:41:36 hificine systemd[1]: Started Wireless Services. Jun 24 17:41:36 hificine kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 24 17:41:36 hificine systemd[1]: Started Volumio Backend Module. Jun 24 17:41:36 hificine systemd[1]: Started Volumio Cpu Tweaker. Jun 24 17:41:36 hificine volumio-cpu-tweak[988]: Setting RT Priority for mpd Jun 24 17:41:36 hificine volumio-cpu-tweak[988]: Setting MPD Affinity Jun 24 17:41:36 hificine volumio-cpu-tweak[988]: pid 810's current affinity mask: f Jun 24 17:41:36 hificine volumio-cpu-tweak[988]: pid 810's new affinity mask: 3 Jun 24 17:41:36 hificine volumio-cpu-tweak[988]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 24 17:41:36 hificine volumio-cpu-tweak[988]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jun 24 17:41:36 hificine systemd[1]: volumio_cpu_tweak.service: Succeeded. Jun 24 17:41:36 hificine ntpd[758]: Listen normally on 3 wlan0 192.168.1.160:123 Jun 24 17:41:36 hificine ntpd[758]: new interface(s) found: waking up resolver Jun 24 17:41:37 hificine nmbd[745]: [2025/06/24 17:41:37.488920, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 24 17:41:37 hificine systemd[1]: Started Samba NMB Daemon. Jun 24 17:41:37 hificine nmbd[745]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 24 17:41:37 hificine systemd[1]: Starting Samba Winbind Daemon... Jun 24 17:41:37 hificine winbindd[1004]: [2025/06/24 17:41:37.859213, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 24 17:41:37 hificine winbindd[1004]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 24 17:41:37 hificine winbindd[1004]: [2025/06/24 17:41:37.919670, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 24 17:41:37 hificine systemd[1]: Started Samba Winbind Daemon. Jun 24 17:41:37 hificine winbindd[1004]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 24 17:41:37 hificine systemd[1]: Starting Samba SMB Daemon... Jun 24 17:41:38 hificine winbindd[1004]: [2025/06/24 17:41:38.461968, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Jun 24 17:41:38 hificine winbindd[1004]: res_names->count = 3, expected 4 Jun 24 17:41:38 hificine smbd[1009]: [2025/06/24 17:41:38.596109, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 24 17:41:38 hificine smbd[1009]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 24 17:41:38 hificine systemd[1]: Started Samba SMB Daemon. Jun 24 17:41:38 hificine systemd[1]: Reached target Multi-User System. Jun 24 17:41:38 hificine systemd[1]: Reached target Graphical Interface. Jun 24 17:41:38 hificine systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 24 17:41:38 hificine systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 24 17:41:38 hificine systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 24 17:41:38 hificine systemd[1]: Startup finished in 15.233s (kernel) + 24.196s (userspace) = 39.429s. Jun 24 17:41:39 hificine volumio[987]: info: ------------------------------------------- Jun 24 17:41:39 hificine volumio[987]: info: ----- Volumio3 ---- Jun 24 17:41:39 hificine volumio[987]: info: ------------------------------------------- Jun 24 17:41:39 hificine volumio[987]: info: ----- System startup ---- Jun 24 17:41:39 hificine volumio[987]: info: ------------------------------------------- Jun 24 17:41:40 hificine volumio[987]: info: MYVOLUMIO Environment detected Jun 24 17:41:40 hificine volumio[987]: info: Plugin folders cleanup Jun 24 17:41:40 hificine volumio[987]: info: Scanning into folder /volumio/app/plugins/ Jun 24 17:41:40 hificine volumio[987]: info: Scanning category audio_interface Jun 24 17:41:40 hificine volumio[987]: info: Scanning category miscellanea Jun 24 17:41:40 hificine volumio[987]: info: Scanning category music_service Jun 24 17:41:40 hificine volumio[987]: info: Scanning category plugins.json Jun 24 17:41:40 hificine volumio[987]: info: Scanning category system_controller Jun 24 17:41:40 hificine volumio[987]: info: Scanning category user_interface Jun 24 17:41:40 hificine volumio[987]: info: Scanning into folder /data/plugins/ Jun 24 17:41:40 hificine volumio[987]: info: Scanning category music_service Jun 24 17:41:40 hificine volumio[987]: info: Scanning category system_controller Jun 24 17:41:40 hificine volumio[987]: info: Scanning category system_hardware Jun 24 17:41:40 hificine volumio[987]: info: Plugin folders cleanup completed Jun 24 17:41:40 hificine volumio[987]: info: ------------------------------------------- Jun 24 17:41:40 hificine volumio[987]: info: ----- Core plugins startup ---- Jun 24 17:41:40 hificine volumio[987]: info: ------------------------------------------- Jun 24 17:41:40 hificine volumio[987]: info: Loading plugins from folder /volumio/app/plugins/ Jun 24 17:41:40 hificine volumio[987]: info: Adding plugin upnp to MyMusic Plugins Jun 24 17:41:40 hificine volumio[987]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 24 17:41:40 hificine volumio[987]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 24 17:41:40 hificine volumio[987]: info: Loading plugins from folder /data/plugins/ Jun 24 17:41:40 hificine volumio[987]: info: Loading plugin "system"... Jun 24 17:41:40 hificine volumio[987]: info: Loading plugin "ampswitch"... Jun 24 17:41:41 hificine volumio[987]: info: Applying required configuration parameters for plugin ampswitch Jun 24 17:41:41 hificine volumio[987]: info: Loading plugin "appearance"... Jun 24 17:41:42 hificine volumio[987]: info: Loading plugin "network"... Jun 24 17:41:42 hificine volumio[987]: info: Refreshing Cached IP Addresses Jun 24 17:41:42 hificine sudo[1033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 24 17:41:42 hificine sudo[1033]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:42 hificine sudo[1033]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:42 hificine sudo[1035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 24 17:41:42 hificine sudo[1035]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:42 hificine sudo[1035]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:42 hificine volumio[987]: info: Loading plugin "services"... Jun 24 17:41:42 hificine volumio[987]: info: Loading plugin "alsa_controller"... Jun 24 17:41:42 hificine sudo[1044]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 24 17:41:42 hificine sudo[1044]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:42 hificine volumio-remote-updater[588]: [2025-06-24 17:41:42] [connect] Successful connection Jun 24 17:41:43 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "wizard"... Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "networkfs"... Jun 24 17:41:43 hificine volumio[987]: info: Starting Udev Watcher for removable devices Jun 24 17:41:43 hificine volumio[987]: info: Ignoring mount for partition: boot Jun 24 17:41:43 hificine volumio[987]: info: Ignoring mount for partition: volumio Jun 24 17:41:43 hificine volumio[987]: info: Ignoring mount for partition: volumio_data Jun 24 17:41:43 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "volumio_command_line_client"... Jun 24 17:41:43 hificine volumio[987]: info: Plugin upnp is not enabled Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "my_music"... Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "mpd"... Jun 24 17:41:43 hificine volumio[987]: info: Plugin upnp_browser is not enabled Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "alarm-clock"... Jun 24 17:41:43 hificine sudo[1044]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "airplay_emulation"... Jun 24 17:41:43 hificine volumio[987]: info: Starting Shairport Sync Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "last_100"... Jun 24 17:41:43 hificine volumio[987]: info: Loading plugin "webradio"... Jun 24 17:41:44 hificine volumio[987]: info: Loading plugin "i2s_dacs"... Jun 24 17:41:44 hificine volumio[987]: info: Loading plugin "volumiodiscovery"... Jun 24 17:41:44 hificine volumio[987]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 24 17:41:44 hificine volumio[987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 24 17:41:44 hificine volumio[987]: *** WARNING *** For more information see Jun 24 17:41:44 hificine node[987]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 24 17:41:44 hificine volumio[987]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 24 17:41:44 hificine volumio[987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 24 17:41:44 hificine volumio[987]: *** WARNING *** For more information see Jun 24 17:41:44 hificine node[987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 24 17:41:44 hificine node[987]: *** WARNING *** For more information see Jun 24 17:41:44 hificine node[987]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 24 17:41:44 hificine node[987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 24 17:41:44 hificine node[987]: *** WARNING *** For more information see Jun 24 17:41:44 hificine volumio[987]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 24 17:41:44 hificine volumio[987]: info: Discovery: Started advertising with name: Hificine Jun 24 17:41:44 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 24 17:41:44 hificine volumio[987]: info: Loading plugin "spop"... Jun 24 17:41:46 hificine volumio[987]: info: Loading plugin "outputs"... Jun 24 17:41:46 hificine volumio[987]: info: Loading plugin "albumart"... Jun 24 17:41:46 hificine volumio[987]: info: Plugin example_plugin is not enabled Jun 24 17:41:46 hificine volumio[987]: info: Loading plugin "inputs"... Jun 24 17:41:46 hificine volumio[987]: info: Loading plugin "updater_comm"... Jun 24 17:41:46 hificine volumio[987]: info: Plugin mpdemulation is not enabled Jun 24 17:41:46 hificine volumio[987]: info: Loading plugin "rest_api"... Jun 24 17:41:46 hificine volumio[987]: info: Loading plugin "websocket"... Jun 24 17:41:46 hificine volumio[987]: info: Starting Socket.io Server version 2.3.0 Jun 24 17:41:46 hificine volumio[987]: info: Loading plugin "onkyo_control"... Jun 24 17:41:46 hificine volumio[987]: Forking 3 albumart workers Jun 24 17:41:47 hificine volumio[987]: info: Applying required configuration parameters for plugin onkyo_control Jun 24 17:41:47 hificine volumio[987]: info: Loading i18n strings for locale en Jun 24 17:41:47 hificine volumio[987]: Updating browse sources language Jun 24 17:41:47 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:41:47 hificine volumio[987]: Starting albumart workers Jun 24 17:41:47 hificine volumio[987]: Starting albumart workers Jun 24 17:41:47 hificine volumio[987]: Starting albumart workers Jun 24 17:41:47 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 24 17:41:47 hificine volumio[987]: info: CoreCommandRouter::initPlayerControls Jun 24 17:41:47 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:47 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:47 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 24 17:41:47 hificine volumio[987]: Express server listening on port 3000 Jun 24 17:41:47 hificine volumio[987]: [Metrics] WebUI: 9s 689.99ms Jun 24 17:41:47 hificine volumio[987]: info: CoreStateMachine::resetVolumioState Jun 24 17:41:47 hificine volumio[987]: info: CoreStateMachine::getcurrentVolume Jun 24 17:41:47 hificine volumio[987]: info: CoreCommandRouter::volumioRetrievevolume Jun 24 17:41:47 hificine volumio[987]: info: Cannot read play queue from file Jun 24 17:41:47 hificine volumio[987]: info: Volumio Network Manager: Network status updated: 2 Jun 24 17:41:48 hificine systemd[1]: systemd-fsckd.service: Succeeded. Jun 24 17:41:48 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 1 Jun 24 17:41:48 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 2 Jun 24 17:41:48 hificine volumio[987]: info: CoreStateMachine::pushState Jun 24 17:41:48 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::volumioPushState Jun 24 17:41:48 hificine volumio[987]: info: CoreStateMachine::updateTrackBlock Jun 24 17:41:48 hificine volumio[987]: info: CorePlayQueue::getTrackBlock Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::volumioRetrievevolume Jun 24 17:41:48 hificine volumio[987]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:41:48 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 4 Jun 24 17:41:48 hificine volumio[987]: info: CoreStateMachine::pushState Jun 24 17:41:48 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::volumioPushState Jun 24 17:41:48 hificine volumio[987]: info: CoreStateMachine::setRepeat null single undefined Jun 24 17:41:48 hificine volumio[987]: info: CoreStateMachine::pushState Jun 24 17:41:48 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::volumioPushState Jun 24 17:41:48 hificine volumio[987]: info: CoreStateMachine::setRandom null Jun 24 17:41:48 hificine volumio[987]: info: CoreStateMachine::pushState Jun 24 17:41:48 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::volumioPushState Jun 24 17:41:48 hificine volumio[987]: info: Setting Device type: Raspberry PI Jun 24 17:41:48 hificine volumio[987]: info: Completed loading Core Plugins Jun 24 17:41:48 hificine volumio[987]: info: Preparing to generate the ALSA configuration file Jun 24 17:41:48 hificine volumio[987]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jun 24 17:41:48 hificine volumio[987]: info: Reading ALSA contributions from plugins. Jun 24 17:41:48 hificine volumio[987]: info: Asound.conf file unchanged, so no further update is needed Jun 24 17:41:48 hificine volumio[987]: info: Output device has changed, restarting MPD Jun 24 17:41:48 hificine volumio[987]: info: Output device has changed, restarting Shairport Sync Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:48 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:41:48 hificine sudo[1136]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 24 17:41:48 hificine sudo[1136]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:48 hificine sudo[1136]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:48 hificine sudo[1138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 24 17:41:48 hificine sudo[1138]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:48 hificine systemd[1]: Stopping Music Player Daemon... Jun 24 17:41:48 hificine volumio[987]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 24 17:41:48 hificine volumio[987]: info: ___________ START PLUGINS ___________ Jun 24 17:41:48 hificine volumio[987]: info: ControllerMpd::onStart: Initializing MPD Jun 24 17:41:48 hificine volumio[987]: info: Creating MPD Configuration file Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:41:49 hificine sudo[1157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 24 17:41:49 hificine sudo[1157]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:49 hificine sudo[1157]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:49 hificine sudo[1159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 24 17:41:49 hificine sudo[1159]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:49 hificine systemd[1]: mpd.service: Succeeded. Jun 24 17:41:49 hificine systemd[1]: Stopped Music Player Daemon. Jun 24 17:41:49 hificine volumio[987]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:41:49 hificine systemd[1]: Starting Music Player Daemon... Jun 24 17:41:49 hificine volumio[987]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 24 17:41:49 hificine systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 24 17:41:49 hificine systemd[1]: mpd.service: Succeeded. Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 24 17:41:49 hificine systemd[1]: Stopped Music Player Daemon. Jun 24 17:41:49 hificine volumio[987]: info: [1750779709138] CoreMusicLibrary::Adding element Last_100 Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 24 17:41:49 hificine volumio[987]: info: [1750779709144] CoreMusicLibrary::Adding element Webradio Jun 24 17:41:49 hificine systemd[1]: Starting Music Player Daemon... Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 24 17:41:49 hificine volumio[987]: info: Initializing BBC Radios Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: Creating Spotify config file Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine sudo[1169]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 24 17:41:49 hificine sudo[1169]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:49 hificine volumio[987]: info: Volumio Calling Home Jun 24 17:41:49 hificine sudo[1169]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:49 hificine volumio[987]: info: Discovery: adding d2e6b880-5939-47c4-8136-5b3f52c22d25 Jun 24 17:41:49 hificine volumio[987]: info: Discovery: Found device Hificine Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:49 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:49 hificine volumio[987]: info: ONKYO-CONTROL: *********** ONKYO PLUGIN STARTED ******** Jun 24 17:41:49 hificine volumio[987]: info: MPD Permissions set Jun 24 17:41:49 hificine volumio[987]: info: MPD Permissions set Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:49 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:49 hificine volumio[987]: info: Volumio called home Jun 24 17:41:49 hificine volumio[987]: info: Spotify config file written Jun 24 17:41:49 hificine sudo[1186]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 24 17:41:49 hificine sudo[1186]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:49 hificine volumio[987]: info: [ASDebug] CurState: stop PrevState: na Jun 24 17:41:49 hificine volumio[987]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Jun 24 17:41:49 hificine volumio[987]: info: [ASDebug] CurState: stop PrevState: na Jun 24 17:41:49 hificine volumio[987]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Jun 24 17:41:49 hificine volumio[987]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 24 17:41:49 hificine volumio[987]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: No need to fix Spotify hosts Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:41:49 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:41:49 hificine systemd[1]: Started go-librespot Daemon. Jun 24 17:41:49 hificine go-librespot[1188]: go-librespot daemon starting... Jun 24 17:41:49 hificine sudo[1186]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:49 hificine volumio[987]: info: Starting Shairport Sync Jun 24 17:41:49 hificine volumio[987]: info: Starting Shairport Sync Jun 24 17:41:49 hificine volumio[987]: info: Starting Shairport Sync Jun 24 17:41:49 hificine sudo[1203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 24 17:41:49 hificine sudo[1203]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:49 hificine sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 24 17:41:49 hificine sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:49 hificine systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 24 17:41:49 hificine sudo[1209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 24 17:41:49 hificine sudo[1209]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:49 hificine systemd[1]: shairport-sync.service: Succeeded. Jun 24 17:41:49 hificine systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 24 17:41:49 hificine sudo[1213]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 24 17:41:49 hificine sudo[1213]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:50 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:50 hificine sudo[1213]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:50 hificine sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 24 17:41:50 hificine sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:50 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:50 hificine sudo[1215]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:50 hificine systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 24 17:41:50 hificine sudo[1203]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:50 hificine sudo[1209]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:50 hificine volumio[987]: info: ONKYO-CONTROL: New state: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":"20","dbVolume":null,"mute":false,"disableVolumeControl":false,"random":null,"repeat":null,"repeatSingle":false,"updatedb":false,"consume":false} connection: {"reconnect":true,"verify_commands":false,"port":60128,"host":"192.168.1.183","model":"TX-NR509"} Jun 24 17:41:50 hificine sudo[1205]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:50 hificine volumio[987]: info: Shairport-Sync Started Jun 24 17:41:50 hificine volumio[987]: Error adding Membership: Error: addMembership EINVAL Jun 24 17:41:50 hificine volumio[987]: info: Shairport-Sync Started Jun 24 17:41:50 hificine volumio[987]: info: Shairport-Sync Started Jun 24 17:41:50 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 7 Jun 24 17:41:50 hificine sh[516]: timed out Jun 24 17:41:50 hificine dhcpcd[553]: timed out Jun 24 17:41:50 hificine sh[516]: dhcpcd exited Jun 24 17:41:50 hificine dhcpcd[553]: dhcpcd exited Jun 24 17:41:50 hificine sh[516]: ifup: failed to bring up eth0 Jun 24 17:41:50 hificine systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jun 24 17:41:50 hificine systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jun 24 17:41:50 hificine volumio[987]: info: [ASDebug] Togle GPIO: OFF Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=info msg="running go-librespot 0.2.0" Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=debug msg="app state loaded" Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=debug msg="stored credentials not found" Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::volumioGetVisibleSources Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:50 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 24 17:41:50 hificine volumio[987]: info: Received Get System Info Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:41:50 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:50 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:50 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:50 hificine volumio[987]: info: Listing playlists Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 24 17:41:50 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 24 17:41:50 hificine go-librespot[1188]: time="2025-06-24T17:41:50+02:00" level=info msg="zeroconf server listening on port 43389" Jun 24 17:41:51 hificine mpd[1182]: Jun 24 17:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 24 17:41:51 hificine systemd[1]: Started Music Player Daemon. Jun 24 17:41:51 hificine sudo[1138]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:51 hificine sudo[1159]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:51 hificine volumio[987]: info: Completed starting Core Plugins Jun 24 17:41:51 hificine volumio[987]: info: ------------------------------------------- Jun 24 17:41:51 hificine volumio[987]: info: ----- MyVolumio plugins startup ---- Jun 24 17:41:51 hificine volumio[987]: info: ------------------------------------------- Jun 24 17:41:51 hificine volumio[987]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 24 17:41:51 hificine volumio[987]: error: MPD error: The expression evaluated to a falsy value: Jun 24 17:41:51 hificine volumio[987]: assert.ok(self.idling) Jun 24 17:41:51 hificine volumio[987]: error: The expression evaluated to a falsy value: Jun 24 17:41:51 hificine volumio[987]: assert.ok(self.idling) Jun 24 17:41:51 hificine volumio[987]: info: MPD running with PID1182 Jun 24 17:41:51 hificine volumio[987]: ,establishing connection Jun 24 17:41:51 hificine volumio[987]: error: updateQueue error: null Jun 24 17:41:51 hificine volumio[987]: error: updateQueue error: null Jun 24 17:41:51 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:41:51 hificine volumio[987]: info: Received Get System Info Jun 24 17:41:51 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:41:51 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:41:51 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:41:51 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:51 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:51 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:41:51 hificine systemd[1]: systemd-hostnamed.service: Succeeded. Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:41:52 hificine volumio[987]: info: Received Get System Info Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:41:52 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:52 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 24 17:41:52 hificine volumio[987]: info: go-librespot daemon successfully initialized Jun 24 17:41:52 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 24 17:41:55 hificine volumio[987]: info: Initializing connection to go-librespot Websocket Jun 24 17:41:55 hificine go-librespot[1188]: time="2025-06-24T17:41:55+02:00" level=debug msg="new websocket client" Jun 24 17:41:55 hificine volumio[987]: info: Connection to go-librespot Websocket established Jun 24 17:41:56 hificine volumio[987]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 24 17:41:57 hificine sudo[1245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 24 17:41:57 hificine sudo[1245]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:57 hificine sudo[1245]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:57 hificine sudo[1247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 24 17:41:57 hificine sudo[1247]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:41:57 hificine sudo[1247]: pam_unix(sudo:session): session closed for user root Jun 24 17:41:57 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 7 Jun 24 17:41:57 hificine volumio-remote-updater[588]: [2025-06-24 17:41:57] [connect] Successful connection Jun 24 17:41:57 hificine volumio-remote-updater[588]: [2025-06-24 17:41:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1750779717 101 Jun 24 17:41:57 hificine volumio[987]: 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: 8 Jun 24 17:41:57 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::volumioGetVisibleSources Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:58 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 24 17:41:58 hificine volumio[987]: info: Received Get System Info Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:41:58 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:58 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:58 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:58 hificine volumio[987]: info: Listing playlists Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 24 17:41:58 hificine volumio[987]: info: Getting Spotify volume Jun 24 17:41:58 hificine volumio[987]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:58 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:58 hificine volumio[987]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Jun 24 17:41:58 hificine volumio[987]: SPOTIFY: SPOTIFY VOLUME undefined Jun 24 17:41:58 hificine volumio[987]: SPOTIFY: VOLUMIO VOLUME 20 Jun 24 17:41:58 hificine volumio[987]: info: Aligning Spotify Volume to Volumio Volume Jun 24 17:41:58 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:41:58 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:41:58 hificine volumio[987]: info: Setting Spotify Volume from Volumio: 20 Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 24 17:41:59 hificine volumio[987]: info: Adding plugin bluetooth to MyMusic Plugins Jun 24 17:41:59 hificine volumio[987]: info: Adding plugin multiroom to MyMusic Plugins Jun 24 17:41:59 hificine volumio[987]: info: Adding plugin metavolumio to MyMusic Plugins Jun 24 17:41:59 hificine volumio[987]: info: Adding plugin cd_controller to MyMusic Plugins Jun 24 17:41:59 hificine volumio[987]: info: Adding plugin qobuzconnect to MyMusic Plugins Jun 24 17:41:59 hificine volumio[987]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 24 17:41:59 hificine volumio[987]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 24 17:41:59 hificine volumio[987]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 24 17:42:00 hificine volumio[987]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 24 17:42:00 hificine volumio[987]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 24 17:42:00 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:00 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:00 hificine volumio[987]: info: Starting MyVolumio Remote Streaming Endpoints Jun 24 17:42:00 hificine volumio[987]: info: MyVolumio login type: Token Jun 24 17:42:00 hificine volumio[987]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 24 17:42:00 hificine volumio[987]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 24 17:42:02 hificine volumio[987]: info: Starting Streaming Service Transparent Proxy Jun 24 17:42:02 hificine volumio[987]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 24 17:42:02 hificine volumio[987]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 24 17:42:02 hificine volumio[987]: info: Streaming services startup Jun 24 17:42:02 hificine volumio[987]: info: Starting Streaming Daemon Jun 24 17:42:02 hificine sudo[1257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 24 17:42:02 hificine sudo[1257]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:02 hificine volumio[987]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 24 17:42:02 hificine sudo[1257]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:02 hificine volumio[987]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Jun 24 17:42:02 hificine volumio[987]: info: Sending Spotify command with payload to local API: /player/volume Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:02 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:02 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:02 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:02 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:02 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:02 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:02 hificine volumio[987]: error: Cannot start Volumio Streaming Daemon Jun 24 17:42:02 hificine volumio[987]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 24 17:42:02 hificine volumio[987]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 24 17:42:02 hificine volumio[987]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Jun 24 17:42:02 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 24 17:42:02 hificine volumio[987]: info: MyVolumio login type: Token Jun 24 17:42:03 hificine volumio[987]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 24 17:42:03 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 24 17:42:03 hificine volumio[987]: info: MyVolumio login type: Token Jun 24 17:42:03 hificine volumio[987]: STREAMING PROXY: Starting server on port 3245 Jun 24 17:42:03 hificine volumio[987]: Node JS runtime: 14 Jun 24 17:42:04 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:04 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 24 17:42:04 hificine volumio[987]: info: MyVolumio token set successfully Jun 24 17:42:04 hificine volumio[987]: info: MYVOLUMIO: Adding device Jun 24 17:42:04 hificine volumio[987]: info: MYVOLUMIO: Evaluating Server Jun 24 17:42:04 hificine volumio[987]: info: MyVolumio status changed Jun 24 17:42:04 hificine volumio[987]: info: Streaming services startup Jun 24 17:42:04 hificine volumio[987]: info: Starting Streaming Daemon Jun 24 17:42:04 hificine volumio[987]: info: Removing browser output: myVolumio user plan is not superstar Jun 24 17:42:04 hificine volumio[987]: info: Removing audio output: Jun 24 17:42:04 hificine volumio[987]: info: Stoppping Tunnel 1 Jun 24 17:42:04 hificine sudo[1296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 24 17:42:04 hificine sudo[1296]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:04 hificine sudo[1296]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:04 hificine sudo[1298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jun 24 17:42:04 hificine sudo[1298]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:04 hificine volumio[987]: error: Cannot start Volumio Streaming Daemon Jun 24 17:42:04 hificine volumio[987]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 24 17:42:04 hificine volumio[987]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 24 17:42:04 hificine sudo[1298]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:04 hificine volumio[987]: info: Remote SSH Stopped Jun 24 17:42:05 hificine volumio[987]: info: Setting Geolocation for MyVolumio to eu10 Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:05 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:05 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:05 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:05 hificine volumio[987]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:05 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:05 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:05 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:05 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:06 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:06 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:06 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:06 hificine volumio[987]: info: Updating MyVolumio device info Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:06 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:06 hificine systemd[1]: systemd-timedated.service: Succeeded. Jun 24 17:42:06 hificine volumio[987]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 24 17:42:07 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.11 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 17:42:07 hificine volumio[987]: info: Starting Uninstall of plugin system_controller - ampswitch Jun 24 17:42:07 hificine volumio[987]: info: Uninstalling plugin ampswitch Jun 24 17:42:07 hificine volumio[987]: info: [ASDebug] Port: 24 Jun 24 17:42:07 hificine volumio[987]: info: [ASDebug] Inverted: false Jun 24 17:42:07 hificine volumio[987]: info: [ASDebug] Delay: 720 Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::volumioGetVisibleSources Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:07 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:07 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 24 17:42:07 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:07 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:07 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:07 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:07 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:07 hificine volumio[987]: info: Listing playlists Jun 24 17:42:08 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 24 17:42:09 hificine volumio[987]: info: MYVOLUMIO: Adding device Jun 24 17:42:09 hificine volumio[987]: info: MYVOLUMIO: Evaluating Server Jun 24 17:42:10 hificine volumio[987]: info: Setting Geolocation for MyVolumio to eu6 Jun 24 17:42:10 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:10 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:10 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:10 hificine volumio[987]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jun 24 17:42:11 hificine volumio[987]: info: Updating MyVolumio device info Jun 24 17:42:11 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:11 hificine volumio[987]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 24 17:42:15 hificine sudo[1337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 24 17:42:15 hificine sudo[1337]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:15 hificine sudo[1337]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:15 hificine sudo[1339]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 24 17:42:15 hificine sudo[1339]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:15 hificine sudo[1339]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:15 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 10 Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::volumioGetVisibleSources Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:15 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 24 17:42:15 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:15 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:15 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:15 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:15 hificine volumio[987]: info: Listing playlists Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 24 17:42:15 hificine volumio[987]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:15 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:15 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 24 17:42:17 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:17 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:17 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:17 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:17 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:17 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:17 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:17 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:17 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 24 17:42:18 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:18 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:18 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:18 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:18 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:18 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:18 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:18 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:19 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 24 17:42:19 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:19 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 17:42:19 hificine volumio-remote-updater[588]: No test mode Jun 24 17:42:19 hificine volumio-remote-updater[588]: No alpha test mode Jun 24 17:42:19 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 24 17:42:19 hificine volumio[987]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 24 17:42:19 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::volumioGetBrowseSources Jun 24 17:42:20 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 24 17:42:20 hificine sudo[1384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 24 17:42:20 hificine sudo[1384]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:21 hificine sudo[1384]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:21 hificine sudo[1387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 24 17:42:21 hificine sudo[1387]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:21 hificine sudo[1387]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:21 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 8 Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::volumioGetVisibleSources Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:21 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 24 17:42:21 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:21 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:21 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:21 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:21 hificine volumio[987]: info: Listing playlists Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 24 17:42:21 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 24 17:42:22 hificine volumio[987]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 24 17:42:22 hificine volumio[987]: info: Completed starting MyVolumio Plugin Jun 24 17:42:22 hificine volumio[987]: [Metrics] CommandRouter: 43s 178.71ms Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::volumiosetStartupVolume Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::Close All Modals sent Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::Close All Modals sent Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:22 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:22 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:22 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:22 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:23 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:23 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:23 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:23 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:25 hificine volumio[987]: info: Starting Uninstall of plugin system_controller - ampswitch Jun 24 17:42:25 hificine volumio[987]: info: Uninstalling plugin ampswitch Jun 24 17:42:25 hificine volumio[987]: info: [ASDebug] Port: 24 Jun 24 17:42:25 hificine volumio[987]: info: [ASDebug] Inverted: false Jun 24 17:42:25 hificine volumio[987]: info: [ASDebug] Delay: 720 Jun 24 17:42:27 hificine sudo[1409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 24 17:42:27 hificine sudo[1409]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:27 hificine sudo[1409]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:27 hificine sudo[1411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 24 17:42:27 hificine sudo[1411]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 24 17:42:27 hificine sudo[1411]: pam_unix(sudo:session): session closed for user root Jun 24 17:42:27 hificine volumio[987]: verbose: New Socket.io Connection to 192.168.1.160 from 192.168.1.53 UA: Mozilla/5.0 (Android 12; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 8 Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::volumioGetVisibleSources Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:27 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 24 17:42:27 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:27 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:27 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:27 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:27 hificine volumio[987]: info: Listing playlists Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 24 17:42:27 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 24 17:42:27 hificine ntpd[758]: Soliciting pool server 212.85.158.10 Jun 24 17:42:28 hificine ntpd[758]: Soliciting pool server 212.83.158.83 Jun 24 17:42:28 hificine ntpd[758]: Soliciting pool server 51.68.44.27 Jun 24 17:42:28 hificine ntpd[758]: Soliciting pool server 162.159.200.1 Jun 24 17:42:28 hificine ntpd[758]: Soliciting pool server 217.182.137.208 Jun 24 17:42:29 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:29 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:29 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:29 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:29 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:29 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:29 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:29 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:29 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 24 17:42:29 hificine volumio[987]: info: BOOT COMPLETED Jun 24 17:42:29 hificine ntpd[758]: Soliciting pool server 129.151.225.244 Jun 24 17:42:29 hificine ntpd[758]: Soliciting pool server 82.64.230.205 Jun 24 17:42:29 hificine ntpd[758]: Soliciting pool server 146.59.88.209 Jun 24 17:42:30 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 24 17:42:30 hificine volumio[987]: info: Received Get System Info Jun 24 17:42:30 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 17:42:30 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 17:42:30 hificine volumio[987]: info: Discovery: Getting this device information Jun 24 17:42:30 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:30 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:30 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 17:42:30 hificine ntpd[758]: Soliciting pool server 109.190.177.203 Jun 24 17:42:30 hificine ntpd[758]: Soliciting pool server 5.135.153.35 Jun 24 17:42:30 hificine ntpd[758]: Soliciting pool server 5.39.80.51 Jun 24 17:42:31 hificine ntpd[758]: Soliciting pool server 82.67.41.119 Jun 24 17:42:31 hificine ntpd[758]: Soliciting pool server 129.250.35.250 Jun 24 17:42:32 hificine ntpd[758]: Soliciting pool server 51.38.186.51 Jun 24 17:42:32 hificine ntpd[758]: Soliciting pool server 212.227.232.161 Jun 24 17:42:32 hificine ntpd[758]: Soliciting pool server 82.64.45.50 Jun 24 17:42:32 hificine ntpd[758]: Soliciting pool server 2a03:7220:8081:2900::1 Jun 24 17:42:32 hificine ntpd[758]: Soliciting pool server 82.64.84.116 Jun 24 17:42:32 hificine ntpd[758]: Soliciting pool server 188.165.49.6 Jun 24 17:42:36 hificine ntpd[758]: receive: Unexpected origin timestamp 0xec0545ea.fbbb9874 does not match aorg 0000000000.00000000 from server@5.135.153.35 xmt 0xec0545ec.168dc34e Jun 24 17:42:36 hificine ntpd[758]: receive: Unexpected origin timestamp 0xec0545ea.fbb9cc10 does not match aorg 0000000000.00000000 from server@5.39.80.51 xmt 0xec0545ec.167565c0 Jun 24 17:42:36 hificine ntpd[758]: receive: Unexpected origin timestamp 0xec0545ea.fbb40c1b does not match aorg 0000000000.00000000 from server@51.38.186.51 xmt 0xec0545ec.16b48897 Jun 24 17:42:36 hificine ntpd[758]: receive: Unexpected origin timestamp 0xec0545ea.fbbf72ac does not match aorg 0000000000.00000000 from server@51.68.44.27 xmt 0xec0545ec.172f681e Jun 24 17:42:36 hificine ntpd[758]: receive: Unexpected origin timestamp 0xec0545ea.fbbe4f62 does not match aorg 0000000000.00000000 from server@129.151.225.244 xmt 0xec0545ec.19a34291 Jun 24 17:42:36 hificine ntpd[758]: receive: Unexpected origin timestamp 0xec0545ea.fbbcd027 does not match aorg 0000000000.00000000 from server@146.59.88.209 xmt 0xec0545ec.196f5bb0 Jun 24 17:42:39 hificine go-librespot[1188]: time="2025-06-24T17:42:39+02:00" level=debug msg="obtained new client token: AABYwFgIqDnjdMfEQ9gCafBBBnRqKGqIkB9RS9MHdUF10SZBI4d/+YbAVaN3FHKaGfOLgdsxYBDe1cKyhZenxrvKNZPsTkHXUtnWvFrHZCWDlijJqsTYwR6+SbPXiDIWLdK5d2lPPxRHMJKYHC1ND7iZzQk5TGa3zTKN5xXRMkJl5vHd8qaU6sAbaziKS0Ac3ScDr89U6L5cMfVrWftMJIN8tUBgMGxjFyWDrq+uNheFOY2paE4Tsm+Xug==" Jun 24 17:42:39 hificine go-librespot[1188]: time="2025-06-24T17:42:39+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jun 24 17:42:39 hificine go-librespot[1188]: time="2025-06-24T17:42:39+02:00" level=debug msg="completed keyexchange" Jun 24 17:42:39 hificine go-librespot[1188]: time="2025-06-24T17:42:39+02:00" level=debug msg="completed challenge" Jun 24 17:42:39 hificine go-librespot[1188]: time="2025-06-24T17:42:39+02:00" level=info msg="authenticated AP as 31brtygg24soonjsxszydlrgzd2u" Jun 24 17:42:39 hificine go-librespot[1188]: time="2025-06-24T17:42:39+02:00" level=info msg="authenticated Login5 as 31brtygg24soonjsxszydlrgzd2u" Jun 24 17:42:39 hificine go-librespot[1188]: time="2025-06-24T17:42:39+02:00" level=info msg="accepted zeroconf user 31brtygg24soonjsxszydlrgzd2u from OPPO Reno4 Z 5G" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="dealer connection opened" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=trace msg="starting accesspoint recv loop" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=trace msg="starting dealer recv loop" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=trace msg="received accesspoint ping" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="received connection id: Y2ZjOTdiYjItZDA2OC00ZGMyLTkyNGItYTU3YWMxMWJhYjlhK2RlYWxlcit0Y3A6Ly8wYWNhNDFhYi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArRjI2NzM3MDNFRDQ1NzM1NzQxQjNDQTczNTRFN0Q1M0FFQzc3N0Q3RjNGNEYxNUMwQUYyQkI1Nzg4MEIzRDY3RQ==" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=trace msg="received accesspoint pong ack" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="handling transfer player command from 17abd17f188ac325aa4831e301d32b9e087a2907" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="resolved context of track" uri="spotify:search:ro" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:search:ro" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="loading track (paused: false, position: 99941ms)" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=trace msg="emitting websocket event: will_play" Jun 24 17:42:40 hificine volumio[987]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2WQ09wqQBIOor7Q0VpIDBK","play_origin":"com.spotify.gaia"}} Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="selected format OGG_VORBIS_320 (53b237a698ce0db1095596b358a7e26c57e735a3)" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="requested aes key for file 53b237a698ce0db1095596b358a7e26c57e735a3, gid: 2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 24 17:42:40 hificine go-librespot[1188]: time="2025-06-24T17:42:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1365" Jun 24 17:42:41 hificine go-librespot[1188]: time="2025-06-24T17:42:41+02:00" level=debug msg="fetched first chunk of 23, total size is 11772576 bytes" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:41 hificine go-librespot[1188]: time="2025-06-24T17:42:41+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1127" Jun 24 17:42:41 hificine go-librespot[1188]: time="2025-06-24T17:42:41+02:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=debug msg="fetched chunk 8/22, size: 524288" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=trace msg="seek to 99941ms (diff: 126ms, samples: 4407398, bytes: 4450023)" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=debug msg="created new output device" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=debug msg="fetched chunk 11/22, size: 524288" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=info msg="loaded track \"Rock That Body\" (paused: false, position: 99941ms, duration: 268840ms, prefetched: false)" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:43 hificine kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=debug msg="fetched chunk 10/22, size: 524288" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:43 hificine go-librespot[1188]: time="2025-06-24T17:42:43+02:00" level=debug msg="fetched chunk 9/22, size: 524288" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=trace msg="scheduling prefetch in 138s" Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=trace msg="emitting websocket event: metadata" Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=trace msg="emitting websocket event: active" Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=debug msg="sending successful reply for dealer request" Jun 24 17:42:44 hificine volumio[987]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2WQ09wqQBIOor7Q0VpIDBK","name":"Rock That Body","artist_names":["Black Eyed Peas"],"album_name":"THE E.N.D. (THE ENERGY NEVER DIES) [Deluxe Version]","album_cover_url":"https://i.scdn.co/image/ab67616d00001e020bd44f5ff9ecc99f7770acc5","position":99941,"duration":268840,"release_date":"year:2009 month:1 day:1","track_number":2,"disc_number":1}} Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 24 17:42:44 hificine volumio[987]: SPOTIFY: received: {"type":"active","data":null} Jun 24 17:42:44 hificine volumio[987]: info: Aligning Spotify Volume to Volumio Volume Jun 24 17:42:44 hificine volumio[987]: info: CoreCommandRouter::volumioGetState Jun 24 17:42:44 hificine volumio[987]: info: CorePlayQueue::getTrack 0 Jun 24 17:42:44 hificine volumio[987]: info: Setting Spotify Volume from Volumio: 20 Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=trace msg="emitting websocket event: playing" Jun 24 17:42:44 hificine volumio[987]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2WQ09wqQBIOor7Q0VpIDBK","play_origin":"com.spotify.gaia"}} Jun 24 17:42:44 hificine volumio[987]: info: Spotify is playing in volatile mode Jun 24 17:42:44 hificine volumio[987]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 24 17:42:44 hificine volumio[987]: SPOTIFY: UNSET VOLATILE Jun 24 17:42:44 hificine volumio[987]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":"20","dbVolume":null,"mute":false,"disableVolumeControl":false,"random":null,"repeat":null,"repeatSingle":false,"updatedb":false,"consume":false} Jun 24 17:42:44 hificine volumio[987]: SPOTIFY: PUSH STATE SPOTIFY Jun 24 17:42:44 hificine volumio[987]: SPOTIFY: {"status":"play","service":"spop","title":"Rock That Body","artist":"Black Eyed Peas","album":"THE E.N.D. (THE ENERGY NEVER DIES) [Deluxe Version]","albumart":"https://i.scdn.co/image/ab67616d00001e020bd44f5ff9ecc99f7770acc5","uri":"spotify:track:2WQ09wqQBIOor7Q0VpIDBK","trackType":"spotify","seek":99941,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 24 17:42:44 hificine volumio[987]: info: CoreCommandRouter::servicePushState Jun 24 17:42:44 hificine volumio[987]: info: CoreStateMachine::pushState Jun 24 17:42:44 hificine volumio[987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 17:42:44 hificine volumio[987]: info: CoreCommandRouter::volumioPushState Jun 24 17:42:44 hificine volumio[987]: info: [ASDebug] CurState: play PrevState: stop Jun 24 17:42:44 hificine volumio[987]: info: [ASDebug] Togle GPIO: ON Jun 24 17:42:44 hificine volumio[987]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 17:42:44 hificine volumio[987]: Error: EBADF: bad file descriptor, write Jun 24 17:42:44 hificine volumio[987]: at Object.writeSync (fs.js:711:3) Jun 24 17:42:44 hificine volumio[987]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Jun 24 17:42:44 hificine volumio[987]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:207:23) Jun 24 17:42:44 hificine volumio[987]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:86) Jun 24 17:42:44 hificine volumio[987]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 24 17:42:44 hificine volumio[987]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) Jun 24 17:42:44 hificine volumio[987]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) Jun 24 17:42:44 hificine volumio[987]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Jun 24 17:42:44 hificine volumio[987]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 24 17:42:44 hificine volumio[987]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) { Jun 24 17:42:44 hificine volumio[987]: errno: -9, Jun 24 17:42:44 hificine volumio[987]: syscall: 'write', Jun 24 17:42:44 hificine volumio[987]: code: 'EBADF' Jun 24 17:42:44 hificine volumio[987]: } Jun 24 17:42:44 hificine volumio[987]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 17:42:44 hificine go-librespot[1188]: time="2025-06-24T17:42:44+02:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:2WQ09wqQBIOor7Q0VpIDBK" Jun 24 17:42:45 hificine sudo[1452]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-24 17:41 Jun 24 17:42:45 hificine sudo[1452]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"