-- Logs begin at Thu 2025-02-20 13:42:52 CET, end at Thu 2025-02-20 13:44:57 CET. -- Feb 20 13:43:00 volumio-242 wireless.js[789]: trying... Feb 20 13:43:00 volumio-242 sudo[1090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:00 volumio-242 sudo[1090]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:00 volumio-242 sudo[1090]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:01 volumio-242 wireless.js[789]: trying... Feb 20 13:43:01 volumio-242 sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:01 volumio-242 sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:01 volumio-242 sudo[1093]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:02 volumio-242 wireless.js[789]: trying... Feb 20 13:43:02 volumio-242 sudo[1096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:02 volumio-242 sudo[1096]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:02 volumio-242 sudo[1096]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:03 volumio-242 wireless.js[789]: trying... Feb 20 13:43:03 volumio-242 sudo[1099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:03 volumio-242 sudo[1099]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:03 volumio-242 sudo[1099]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:04 volumio-242 volumio-time-update[780]: volumio-time-update-util: Fetching time from Volumio... Feb 20 13:43:04 volumio-242 volumio-time-update[780]: volumio-time-update-util: Date not found in response Feb 20 13:43:04 volumio-242 volumio-time-update[780]: volumio-time-update-util: Retrying in 5 seconds... Feb 20 13:43:04 volumio-242 wpa_supplicant[1067]: wlan0: Trying to associate with SSID 'Asus-AX3000' Feb 20 13:43:04 volumio-242 wireless.js[789]: trying... Feb 20 13:43:04 volumio-242 sudo[1107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:04 volumio-242 sudo[1107]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:04 volumio-242 sudo[1107]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: carrier acquired Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: connected to Access Point `Asus-AX3000' Feb 20 13:43:05 volumio-242 wpa_supplicant[1067]: wlan0: Associated with c8:7f:54:b9:46:10 Feb 20 13:43:05 volumio-242 wpa_supplicant[1067]: wlan0: CTRL-EVENT-CONNECTED - Connection to c8:7f:54:b9:46:10 completed [id=0 id_str=] Feb 20 13:43:05 volumio-242 wpa_supplicant[1067]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 20 13:43:05 volumio-242 wpa_supplicant[1067]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Feb 20 13:43:05 volumio-242 dhcpcd[1079]: DUID 00:01:00:01:2e:f2:a8:12:2c:cf:67:7d:48:b3 Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: IAID 67:7d:48:b3 Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: adding address fe80::5915:a7cb:595e:b7de Feb 20 13:43:05 volumio-242 dhcpcd[1079]: ipv6_addaddr1: Permission denied Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: carrier lost Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: carrier acquired Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: IAID 67:7d:48:b3 Feb 20 13:43:05 volumio-242 dhcpcd[1079]: wlan0: soliciting an IPv6 router Feb 20 13:43:05 volumio-242 wireless.js[789]: trying... Feb 20 13:43:05 volumio-242 sudo[1126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:05 volumio-242 sudo[1126]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:05 volumio-242 sudo[1126]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:06 volumio-242 dhcpcd[1079]: wlan0: rebinding lease of 192.168.50.218 Feb 20 13:43:06 volumio-242 wireless.js[789]: trying... Feb 20 13:43:06 volumio-242 sudo[1129]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:06 volumio-242 sudo[1129]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:06 volumio-242 sudo[1129]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:06 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:06] [info] asio async_connect error: system:111 (Connection refused) Feb 20 13:43:06 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:06] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 20 13:43:06 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:06] [error] handle_connect error: Underlying Transport Error Feb 20 13:43:07 volumio-242 wireless.js[789]: trying... Feb 20 13:43:07 volumio-242 sudo[1132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:07 volumio-242 sudo[1132]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:07 volumio-242 sudo[1132]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:08 volumio-242 wireless.js[789]: trying... Feb 20 13:43:08 volumio-242 sudo[1135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:08 volumio-242 sudo[1135]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:08 volumio-242 sudo[1135]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:09 volumio-242 volumio-time-update[780]: volumio-time-update-util: Fetching time from Volumio... Feb 20 13:43:09 volumio-242 volumio-time-update[780]: volumio-time-update-util: Date not found in response Feb 20 13:43:09 volumio-242 volumio-time-update[780]: volumio-time-update-util: Retrying in 5 seconds... Feb 20 13:43:09 volumio-242 wireless.js[789]: trying... Feb 20 13:43:09 volumio-242 sudo[1143]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:09 volumio-242 sudo[1143]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:09 volumio-242 sudo[1143]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:10 volumio-242 wireless.js[789]: trying... Feb 20 13:43:10 volumio-242 sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:10 volumio-242 sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:10 volumio-242 sudo[1146]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:11 volumio-242 dhcpcd[1079]: wlan0: probing for an IPv4LL address Feb 20 13:43:11 volumio-242 dhcpcd[1079]: wlan0: DHCP lease expired Feb 20 13:43:11 volumio-242 dhcpcd[1079]: wlan0: soliciting a DHCP lease Feb 20 13:43:11 volumio-242 wireless.js[789]: trying... Feb 20 13:43:11 volumio-242 sudo[1158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:11 volumio-242 sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:11 volumio-242 sudo[1158]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:12 volumio-242 wireless.js[789]: trying... Feb 20 13:43:12 volumio-242 sudo[1161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:12 volumio-242 sudo[1161]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:12 volumio-242 sudo[1161]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:13 volumio-242 wireless.js[789]: trying... Feb 20 13:43:13 volumio-242 sudo[1164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:13 volumio-242 sudo[1164]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:13 volumio-242 sudo[1164]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:14 volumio-242 volumio-time-update[780]: volumio-time-update-util: Fetching time from Volumio... Feb 20 13:43:14 volumio-242 volumio-time-update[780]: volumio-time-update-util: Date not found in response Feb 20 13:43:14 volumio-242 volumio-time-update[780]: volumio-time-update-util: Retrying in 5 seconds... Feb 20 13:43:14 volumio-242 wireless.js[789]: trying... Feb 20 13:43:14 volumio-242 sudo[1172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:14 volumio-242 sudo[1172]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:14 volumio-242 sudo[1172]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:15 volumio-242 wireless.js[789]: trying... Feb 20 13:43:15 volumio-242 sudo[1178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:15 volumio-242 sudo[1178]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:15 volumio-242 sudo[1178]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:16 volumio-242 dhcpcd[1079]: wlan0: using IPv4LL address 169.254.96.39 Feb 20 13:43:16 volumio-242 avahi-daemon[799]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.96.39. Feb 20 13:43:16 volumio-242 avahi-daemon[799]: New relevant interface wlan0.IPv4 for mDNS. Feb 20 13:43:16 volumio-242 dhcpcd[1079]: wlan0: adding route to 169.254.0.0/16 Feb 20 13:43:16 volumio-242 avahi-daemon[799]: Registering new address record for 169.254.96.39 on wlan0.IPv4. Feb 20 13:43:16 volumio-242 dhcpcd[1079]: wlan0: adding default route Feb 20 13:43:16 volumio-242 wireless.js[789]: trying... Feb 20 13:43:16 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:16] [info] asio async_connect error: system:111 (Connection refused) Feb 20 13:43:16 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:16] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 20 13:43:16 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:16] [error] handle_connect error: Underlying Transport Error Feb 20 13:43:16 volumio-242 sudo[1192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 20 13:43:16 volumio-242 sudo[1192]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:16 volumio-242 sudo[1192]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:16 volumio-242 wireless.js[789]: Connected to: ----Asus-AX3000 Feb 20 13:43:16 volumio-242 wireless.js[789]: ---- Feb 20 13:43:16 volumio-242 sudo[1195]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 20 13:43:16 volumio-242 sudo[1195]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:16 volumio-242 sudo[1195]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:16 volumio-242 wireless.js[789]: ... joined AP, wlan0 IPv4 is 169.254.96.39, ipV6 is undefined Feb 20 13:43:16 volumio-242 wireless.js[789]: It's done! AP Feb 20 13:43:16 volumio-242 systemd[1]: Started Wireless Services. Feb 20 13:43:16 volumio-242 systemd[1]: Started Volumio Backend Module. Feb 20 13:43:16 volumio-242 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Feb 20 13:43:16 volumio-242 systemd[1]: Started Volumio Cpu Tweaker. Feb 20 13:43:16 volumio-242 volumio-cpu-tweak[1201]: Setting RT Priority for mpd Feb 20 13:43:16 volumio-242 volumio-cpu-tweak[1201]: Setting MPD Affinity Feb 20 13:43:16 volumio-242 volumio-cpu-tweak[1201]: pid 993's current affinity mask: f Feb 20 13:43:16 volumio-242 volumio-cpu-tweak[1201]: pid 993's new affinity mask: 3 Feb 20 13:43:16 volumio-242 volumio-cpu-tweak[1201]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Feb 20 13:43:16 volumio-242 volumio-cpu-tweak[1201]: VOLUMIO CPU TWEAK: Setting CPU Governor: conservative Feb 20 13:43:16 volumio-242 systemd[1]: volumio_cpu_tweak.service: Succeeded. Feb 20 13:43:17 volumio-242 volumio[1200]: info: ------------------------------------------- Feb 20 13:43:17 volumio-242 volumio[1200]: info: ----- Volumio3 ---- Feb 20 13:43:17 volumio-242 volumio[1200]: info: ------------------------------------------- Feb 20 13:43:17 volumio-242 volumio[1200]: info: ----- System startup ---- Feb 20 13:43:17 volumio-242 volumio[1200]: info: ------------------------------------------- Feb 20 13:43:17 volumio-242 ntpd[965]: Listen normally on 3 wlan0 169.254.96.39:123 Feb 20 13:43:17 volumio-242 ntpd[965]: new interface(s) found: waking up resolver Feb 20 13:43:17 volumio-242 volumio[1200]: info: MYVOLUMIO Environment detected Feb 20 13:43:17 volumio-242 volumio[1200]: info: Plugin folders cleanup Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning into folder /volumio/app/plugins/ Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category audio_interface Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category miscellanea Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category music_service Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category plugins.json Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category system_controller Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category user_interface Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning into folder /data/plugins/ Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category music_service Feb 20 13:43:17 volumio-242 volumio[1200]: info: Scanning category system_hardware Feb 20 13:43:17 volumio-242 volumio[1200]: info: Plugin folders cleanup completed Feb 20 13:43:17 volumio-242 volumio[1200]: info: ------------------------------------------- Feb 20 13:43:17 volumio-242 volumio[1200]: info: ----- Core plugins startup ---- Feb 20 13:43:17 volumio-242 volumio[1200]: info: ------------------------------------------- Feb 20 13:43:17 volumio-242 volumio[1200]: info: Loading plugins from folder /volumio/app/plugins/ Feb 20 13:43:17 volumio-242 volumio[1200]: info: Adding plugin upnp to MyMusic Plugins Feb 20 13:43:17 volumio-242 volumio[1200]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 20 13:43:17 volumio-242 volumio[1200]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 20 13:43:17 volumio-242 volumio[1200]: info: Loading plugins from folder /data/plugins/ Feb 20 13:43:17 volumio-242 volumio[1200]: info: Loading plugin "system"... Feb 20 13:43:17 volumio-242 volumio[1200]: info: Loading plugin "appearance"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "network"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Refreshing Cached IP Addresses Feb 20 13:43:18 volumio-242 sudo[1231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 20 13:43:18 volumio-242 sudo[1231]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:18 volumio-242 sudo[1231]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:18 volumio-242 sudo[1233]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 20 13:43:18 volumio-242 sudo[1233]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:18 volumio-242 sudo[1233]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "services"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "alsa_controller"... Feb 20 13:43:18 volumio-242 sudo[1246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 20 13:43:18 volumio-242 sudo[1246]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:18 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "wizard"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "networkfs"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Starting Udev Watcher for removable devices Feb 20 13:43:18 volumio-242 volumio[1200]: info: Ignoring mount for partition: boot Feb 20 13:43:18 volumio-242 volumio[1200]: info: Ignoring mount for partition: volumio Feb 20 13:43:18 volumio-242 volumio[1200]: info: Ignoring mount for partition: volumio_data Feb 20 13:43:18 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "volumio_command_line_client"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "upnp"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: [1740055398195] Starting Upmpd Daemon Feb 20 13:43:18 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "my_music"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "mpd"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "upnp_browser"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "alarm-clock"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "airplay_emulation"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Starting Shairport Sync Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "last_100"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "webradio"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "i2s_dacs"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "volumiodiscovery"... Feb 20 13:43:18 volumio-242 volumio[1200]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 20 13:43:18 volumio-242 node[1200]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 20 13:43:18 volumio-242 volumio[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 13:43:18 volumio-242 volumio[1200]: *** WARNING *** For more information see Feb 20 13:43:18 volumio-242 volumio[1200]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 20 13:43:18 volumio-242 volumio[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 13:43:18 volumio-242 volumio[1200]: *** WARNING *** For more information see Feb 20 13:43:18 volumio-242 node[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 13:43:18 volumio-242 node[1200]: *** WARNING *** For more information see Feb 20 13:43:18 volumio-242 node[1200]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 20 13:43:18 volumio-242 node[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 13:43:18 volumio-242 node[1200]: *** WARNING *** For more information see Feb 20 13:43:18 volumio-242 volumio[1200]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 20 13:43:18 volumio-242 volumio[1200]: info: Discovery: Started advertising with name: Volumio 242 Feb 20 13:43:18 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "spop"... Feb 20 13:43:18 volumio-242 volumio[1200]: info: Loading plugin "outputs"... Feb 20 13:43:19 volumio-242 volumio[1200]: info: Loading plugin "albumart"... Feb 20 13:43:19 volumio-242 volumio[1200]: info: Plugin example_plugin is not enabled Feb 20 13:43:19 volumio-242 volumio[1200]: info: Loading plugin "inputs"... Feb 20 13:43:19 volumio-242 volumio[1200]: info: Loading plugin "updater_comm"... Feb 20 13:43:19 volumio-242 volumio[1200]: info: Plugin mpdemulation is not enabled Feb 20 13:43:19 volumio-242 volumio[1200]: info: Loading plugin "rest_api"... Feb 20 13:43:19 volumio-242 volumio[1200]: info: Loading plugin "websocket"... Feb 20 13:43:19 volumio-242 volumio[1200]: info: Starting Socket.io Server version 2.3.0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: Loading plugin "mpd_oled"... Feb 20 13:43:19 volumio-242 volumio[1200]: Forking 3 albumart workers Feb 20 13:43:19 volumio-242 volumio[1200]: info: Applying required configuration parameters for plugin mpd_oled Feb 20 13:43:19 volumio-242 volumio[1200]: info: [MPD_OLED Plugin] Reading configuration file at: /data/configuration/system_hardware/mpd_oled/config.json Feb 20 13:43:19 volumio-242 volumio[1200]: info: Loading i18n strings for locale sv Feb 20 13:43:19 volumio-242 volumio[1200]: Updating browse sources language Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 13:43:19 volumio-242 volumio[1200]: Starting albumart workers Feb 20 13:43:19 volumio-242 volumio[1200]: Starting albumart workers Feb 20 13:43:19 volumio-242 volumio[1200]: Starting albumart workers Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::initPlayerControls Feb 20 13:43:19 volumio-242 volumio-time-update[780]: volumio-time-update-util: Fetching time from Volumio... Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: Express server listening on port 3000 Feb 20 13:43:19 volumio-242 volumio[1200]: [Metrics] WebUI: 2s 108.71ms Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::resetVolumioState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::getcurrentVolume Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioRetrievevolume Feb 20 13:43:19 volumio-242 volumio[1200]: info: Cannot read play queue from file Feb 20 13:43:19 volumio-242 volumio[1200]: info: Volumio Network Manager: Network status updated: 2 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::setRepeat null single undefined Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::pushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::setRandom null Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::pushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: VolumeController:: Volume=0 Mute =true Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::pushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::updateTrackBlock Feb 20 13:43:19 volumio-242 volumio[1200]: info: CorePlayQueue::getTrackBlock Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioRetrievevolume Feb 20 13:43:19 volumio-242 volumio[1200]: info: Setting Device type: Raspberry PI Feb 20 13:43:19 volumio-242 volumio[1200]: info: Completed loading Core Plugins Feb 20 13:43:19 volumio-242 volumio[1200]: info: Preparing to generate the ALSA configuration file Feb 20 13:43:19 volumio-242 volumio[1200]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Feb 20 13:43:19 volumio-242 volumio[1200]: info: Reading ALSA contributions from plugins. Feb 20 13:43:19 volumio-242 volumio[1200]: info: Asound.conf file unchanged, so no further update is needed Feb 20 13:43:19 volumio-242 volumio[1200]: info: Output device has changed, restarting MPD Feb 20 13:43:19 volumio-242 sudo[1331]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 20 13:43:19 volumio-242 volumio[1200]: info: Output device has changed, restarting Shairport Sync Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 sudo[1331]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 sudo[1331]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 sudo[1333]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 20 13:43:19 volumio-242 sudo[1333]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 systemd[1]: Stopping Music Player Daemon... Feb 20 13:43:19 volumio-242 volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: ___________ START PLUGINS ___________ Feb 20 13:43:19 volumio-242 volumio[1200]: info: ControllerMpd::onStart: Initializing MPD Feb 20 13:43:19 volumio-242 volumio[1200]: info: Creating MPD Configuration file Feb 20 13:43:19 volumio-242 sudo[1340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 20 13:43:19 volumio-242 sudo[1340]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:19 volumio-242 sudo[1340]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 13:43:19 volumio-242 volumio[1200]: info: [1740055399512] CoreMusicLibrary::Adding element Mediaservrar Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 13:43:19 volumio-242 sudo[1343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 20 13:43:19 volumio-242 sudo[1343]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 systemd[1]: mpd.service: Succeeded. Feb 20 13:43:19 volumio-242 systemd[1]: Stopped Music Player Daemon. Feb 20 13:43:19 volumio-242 volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 13:43:19 volumio-242 volumio[1200]: info: [1740055399556] CoreMusicLibrary::Adding element Last_100 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 13:43:19 volumio-242 volumio[1200]: info: [1740055399556] CoreMusicLibrary::Adding element Webradio Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 13:43:19 volumio-242 volumio[1200]: info: Initializing BBC Radios Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: Creating Spotify config file Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 systemd[1]: Starting Music Player Daemon... Feb 20 13:43:19 volumio-242 sudo[1351]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 20 13:43:19 volumio-242 sudo[1351]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 sudo[1351]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 20 13:43:19 volumio-242 volumio[1200]: info: [MPD_OLED Plugin] Not starting mpd_oled service because oled type is not configured yet Feb 20 13:43:19 volumio-242 volumio[1200]: info: Volumio Calling Home Feb 20 13:43:19 volumio-242 volumio[1200]: info: Preparing to generate the ALSA configuration file Feb 20 13:43:19 volumio-242 volumio[1200]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Feb 20 13:43:19 volumio-242 volumio[1200]: info: Reading ALSA contributions from plugins. Feb 20 13:43:19 volumio-242 volumio[1200]: info: MPD Permissions set Feb 20 13:43:19 volumio-242 volumio[1200]: info: MPD Permissions set Feb 20 13:43:19 volumio-242 volumio[1200]: info: VolumeController:: Volume=0 Mute =true Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreStateMachine::pushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: No need to fix Spotify hosts Feb 20 13:43:19 volumio-242 volumio[1200]: info: Spotify config file written Feb 20 13:43:19 volumio-242 volumio[1200]: info: Starting Shairport Sync Feb 20 13:43:19 volumio-242 sudo[1378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 20 13:43:19 volumio-242 sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 volumio[1200]: info: Starting Shairport Sync Feb 20 13:43:19 volumio-242 sudo[1381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 20 13:43:19 volumio-242 sudo[1381]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 volumio[1200]: info: Starting Shairport Sync Feb 20 13:43:19 volumio-242 sudo[1385]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 20 13:43:19 volumio-242 sudo[1385]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 volumio[1200]: info: Asound.conf file unchanged, so no further update is needed Feb 20 13:43:19 volumio-242 volumio[1200]: info: Output device has changed, restarting MPD Feb 20 13:43:19 volumio-242 systemd[1]: Started go-librespot Daemon. Feb 20 13:43:19 volumio-242 sudo[1388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 20 13:43:19 volumio-242 sudo[1388]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 go-librespot[1384]: go-librespot daemon starting... Feb 20 13:43:19 volumio-242 sudo[1390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 20 13:43:19 volumio-242 sudo[1390]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 sudo[1390]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 volumio[1200]: info: Output device has changed, restarting Shairport Sync Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 20 13:43:19 volumio-242 sudo[1378]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 sudo[1395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 20 13:43:19 volumio-242 sudo[1395]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 systemd[1]: shairport-sync.service: Succeeded. Feb 20 13:43:19 volumio-242 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 20 13:43:19 volumio-242 volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 20 13:43:19 volumio-242 volumio[1200]: info: MPD Permissions set Feb 20 13:43:19 volumio-242 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 20 13:43:19 volumio-242 sudo[1388]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 sudo[1381]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 sudo[1385]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Feb 20 13:43:19 volumio-242 systemd[1]: mpd.service: Succeeded. Feb 20 13:43:19 volumio-242 systemd[1]: Stopped Music Player Daemon. Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:19 volumio-242 systemd[1]: Starting Music Player Daemon... Feb 20 13:43:19 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:19 volumio-242 volumio[1200]: info: Shairport-Sync Started Feb 20 13:43:19 volumio-242 volumio[1200]: Error adding Membership: Error: addMembership EINVAL Feb 20 13:43:19 volumio-242 volumio[1200]: info: Shairport-Sync Started Feb 20 13:43:19 volumio-242 volumio[1200]: info: Shairport-Sync Started Feb 20 13:43:19 volumio-242 volumio[1200]: info: Starting Shairport Sync Feb 20 13:43:19 volumio-242 sudo[1413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 20 13:43:19 volumio-242 sudo[1413]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 sudo[1406]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 20 13:43:19 volumio-242 sudo[1406]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:19 volumio-242 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 20 13:43:19 volumio-242 systemd[1]: shairport-sync.service: Succeeded. Feb 20 13:43:19 volumio-242 sudo[1406]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 20 13:43:19 volumio-242 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 20 13:43:19 volumio-242 sudo[1413]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 volumio[1200]: info: Shairport-Sync Started Feb 20 13:43:19 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:19+01:00" level=info msg="running go-librespot 0.2.0" Feb 20 13:43:19 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:19+01:00" level=debug msg="app state loaded" Feb 20 13:43:19 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 20 13:43:19 volumio-242 nmbd[900]: [2025/02/20 13:43:19.913479, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 20 13:43:19 volumio-242 nmbd[900]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Feb 20 13:43:19 volumio-242 systemd[1]: Started Samba NMB Daemon. Feb 20 13:43:19 volumio-242 systemd[1]: Starting Samba Winbind Daemon... Feb 20 13:43:19 volumio-242 mpd[1417]: Feb 20 13:43 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 20 13:43:19 volumio-242 systemd[1]: Started Music Player Daemon. Feb 20 13:43:19 volumio-242 sudo[1333]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 sudo[1395]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 sudo[1343]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:19 volumio-242 volumio[1200]: info: Completed starting Core Plugins Feb 20 13:43:19 volumio-242 volumio[1200]: info: ------------------------------------------- Feb 20 13:43:19 volumio-242 volumio[1200]: info: ----- MyVolumio plugins startup ---- Feb 20 13:43:19 volumio-242 volumio[1200]: info: ------------------------------------------- Feb 20 13:43:19 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 20 13:43:20 volumio-242 winbindd[1421]: [2025/02/20 13:43:20.014752, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Feb 20 13:43:20 volumio-242 winbindd[1421]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 20 13:43:20 volumio-242 volumio[1200]: error: MPD error: The expression evaluated to a falsy value: Feb 20 13:43:20 volumio-242 volumio[1200]: assert.ok(self.idling) Feb 20 13:43:20 volumio-242 volumio[1200]: error: The expression evaluated to a falsy value: Feb 20 13:43:20 volumio-242 volumio[1200]: assert.ok(self.idling) Feb 20 13:43:20 volumio-242 volumio[1200]: info: MPD running with PID1417 Feb 20 13:43:20 volumio-242 volumio[1200]: ,establishing connection Feb 20 13:43:20 volumio-242 volumio[1200]: error: MPD error: The expression evaluated to a falsy value: Feb 20 13:43:20 volumio-242 volumio[1200]: assert.ok(self.idling) Feb 20 13:43:20 volumio-242 volumio[1200]: error: The expression evaluated to a falsy value: Feb 20 13:43:20 volumio-242 volumio[1200]: assert.ok(self.idling) Feb 20 13:43:20 volumio-242 volumio[1200]: error: MPD error: The expression evaluated to a falsy value: Feb 20 13:43:20 volumio-242 volumio[1200]: assert.ok(self.idling) Feb 20 13:43:20 volumio-242 volumio[1200]: error: The expression evaluated to a falsy value: Feb 20 13:43:20 volumio-242 volumio[1200]: assert.ok(self.idling) Feb 20 13:43:20 volumio-242 volumio[1200]: error: updateQueue error: null Feb 20 13:43:20 volumio-242 winbindd[1421]: [2025/02/20 13:43:20.036558, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 20 13:43:20 volumio-242 systemd[1]: Started Samba Winbind Daemon. Feb 20 13:43:20 volumio-242 winbindd[1421]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Feb 20 13:43:20 volumio-242 systemd[1]: Starting Samba SMB Daemon... Feb 20 13:43:20 volumio-242 smbd[1430]: [2025/02/20 13:43:20.202925, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 20 13:43:20 volumio-242 systemd[1]: Started Samba SMB Daemon. Feb 20 13:43:20 volumio-242 smbd[1430]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Feb 20 13:43:21 volumio-242 sudo[1246]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:22 volumio-242 volumio[1200]: info: go-librespot daemon successfully initialized Feb 20 13:43:23 volumio-242 systemd[1]: systemd-fsckd.service: Succeeded. Feb 20 13:43:23 volumio-242 sh[690]: timed out Feb 20 13:43:23 volumio-242 dhcpcd[751]: timed out Feb 20 13:43:23 volumio-242 sh[690]: dhcpcd exited Feb 20 13:43:23 volumio-242 dhcpcd[751]: dhcpcd exited Feb 20 13:43:23 volumio-242 sh[690]: ifup: failed to bring up eth0 Feb 20 13:43:23 volumio-242 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Feb 20 13:43:23 volumio-242 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Feb 20 13:43:24 volumio-242 dhcpcd[1079]: wlan0: offered 192.168.50.218 from 192.168.50.1 Feb 20 13:43:24 volumio-242 dhcpcd[1079]: wlan0: probing address 192.168.50.218/24 Feb 20 13:43:24 volumio-242 systemd[1]: systemd-hostnamed.service: Succeeded. Feb 20 13:43:25 volumio-242 volumio[1200]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 20 13:43:25 volumio-242 volumio[1200]: info: Initializing connection to go-librespot Websocket Feb 20 13:43:26 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:26] [connect] Successful connection Feb 20 13:43:26 volumio-242 volumio-remote-updater[786]: [2025-02-20 13:43:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740055406 101 Feb 20 13:43:26 volumio-242 volumio[1200]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Feb 20 13:43:28 volumio-242 sudo[1460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 20 13:43:28 volumio-242 sudo[1460]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:28 volumio-242 sudo[1460]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:28 volumio-242 sudo[1462]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 20 13:43:28 volumio-242 sudo[1462]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:28 volumio-242 sudo[1462]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:28 volumio-242 sudo[1466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 20 13:43:28 volumio-242 sudo[1466]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:28 volumio-242 systemd[1]: Started UPnP Renderer front-end to MPD. Feb 20 13:43:28 volumio-242 sudo[1466]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:28 volumio-242 volumio[1200]: info: Upmpdcli Daemon Started Feb 20 13:43:28 volumio-242 volumio[1468]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 20 13:43:29 volumio-242 dhcpcd[1079]: wlan0: leased 192.168.50.218 for 86400 seconds Feb 20 13:43:29 volumio-242 avahi-daemon[799]: Registering new address record for 192.168.50.218 on wlan0.IPv4. Feb 20 13:43:29 volumio-242 dhcpcd[1079]: wlan0: adding route to 192.168.50.0/24 Feb 20 13:43:29 volumio-242 dhcpcd[1079]: wlan0: changing default route via 192.168.50.1 Feb 20 13:43:29 volumio-242 avahi-daemon[799]: Withdrawing address record for 169.254.96.39 on wlan0. Feb 20 13:43:29 volumio-242 avahi-daemon[799]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.96.39. Feb 20 13:43:29 volumio-242 dhcpcd[1079]: wlan0: deleting route to 169.254.0.0/16 Feb 20 13:43:29 volumio-242 avahi-daemon[799]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.50.218. Feb 20 13:43:29 volumio-242 dhcpcd[1079]: wlan0: pid 1079 deleted default route via 192.168.50.1 Feb 20 13:43:29 volumio-242 volumio[1200]: info: Discovery: adding 47b65369-02b4-47bc-ac44-d2c6125cfe60 Feb 20 13:43:29 volumio-242 volumio[1200]: info: Discovery: Found device Volumio 242 Feb 20 13:43:29 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:29 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:29 volumio-242 volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 20 13:43:29 volumio-242 volumio[1200]: info: Connection to go-librespot Websocket established Feb 20 13:43:29 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:29+01:00" level=debug msg="new websocket client" Feb 20 13:43:29 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:29 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:29 volumio-242 volumio[1468]: ...........................++++ Feb 20 13:43:29 volumio-242 volumio[1200]: info: Volumio called home Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=info msg="zeroconf server listening on port 32883" Feb 20 13:43:30 volumio-242 volumio[1200]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 20 13:43:30 volumio-242 volumio[1200]: SPOTIFY: BQCFzi6cDZGnB6eBmQK21D1yg3QW23Xvn7m6-p1Y-ldqSQjWV1yHalQgunMnQ8SU5C1eE9ix1jVsyD06jO4fXKadL3-Y-UwHILfmSFYyIX2K-wt97yyUq0ZLafFibHGskjttJz7Z3By3Lk8bt06evXWnJjc04L8sWmNb794O933jPMouYCZccJ5N-ICgJhefBqwvUGQgXo39Pzr8AqLBCs5f7H3uazSgCStial_adOb-p8EbfWrzY6fTyjNO9IHDdeY7IfoKtUiyBg Feb 20 13:43:30 volumio-242 volumio[1200]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 20 13:43:30 volumio-242 volumio[1200]: info: New Spotify access token = BQCFzi6cDZGnB6eBmQK21D1yg3QW23Xvn7m6-p1Y-ldqSQjWV1yHalQgunMnQ8SU5C1eE9ix1jVsyD06jO4fXKadL3-Y-UwHILfmSFYyIX2K-wt97yyUq0ZLafFibHGskjttJz7Z3By3Lk8bt06evXWnJjc04L8sWmNb794O933jPMouYCZccJ5N-ICgJhefBqwvUGQgXo39Pzr8AqLBCs5f7H3uazSgCStial_adOb-p8EbfWrzY6fTyjNO9IHDdeY7IfoKtUiyBg Feb 20 13:43:30 volumio-242 volumio[1200]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="obtained new client token: AACA8mYCitXYt+097bjguqvC2tndmNr9PK/CcbLFYRUvJJyhz7O0/U7jOc51jl5fkTOt+WJ8nqlZeSTrL9v7ipOxuJP3F5imOPMOVvt3G0Bjm+iWwR4K5iBmNN752X89dbatSBL9b0DDJ2WzY8tVEFarCyKX87lI6if+P0mCq6QjpxtsM7QwM0zpcXTIMT4LwqwagqmQnWWonvNsqd6CsmiR0+SWEGeb2r4m19tE/E51B2hi3V2/hirc0VI=" Feb 20 13:43:30 volumio-242 volumio[1200]: verbose: New Socket.io Connection to 192.168.50.218 from 192.168.50.99 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 20 13:43:30 volumio-242 volumio[1200]: verbose: New Socket.io Connection to 192.168.50.218 from 192.168.50.99 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 20 13:43:30 volumio-242 volumio[1200]: SPOTIFY: User informations: {"country":"SE","display_name":"peguzz","email":"p3.gustafsson@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/peguzz"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/peguzz","id":"peguzz","images":[],"product":"premium","type":"user","uri":"spotify:user:peguzz"} Feb 20 13:43:30 volumio-242 volumio[1200]: info: Spotify Successfully logged in Feb 20 13:43:30 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 13:43:30 volumio-242 volumio[1200]: info: [1740055410364] CoreMusicLibrary::Adding element Spotify Feb 20 13:43:30 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 13:43:30 volumio-242 volumio[1200]: Cannot find translation for source Spotify Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="completed keyexchange" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="completed challenge" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=info msg="authenticated AP as peguzz" Feb 20 13:43:30 volumio-242 ntpd[965]: Listen normally on 4 wlan0 192.168.50.218:123 Feb 20 13:43:30 volumio-242 ntpd[965]: Deleting interface #3 wlan0, 169.254.96.39#123, interface stats: received=0, sent=0, dropped=0, active_time=13 secs Feb 20 13:43:30 volumio-242 ntpd[965]: new interface(s) found: waking up resolver Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=info msg="authenticated Login5 as peguzz" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="initializing zeroconf session, username: peguzz" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="dealer connection opened" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=trace msg="starting accesspoint recv loop" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=trace msg="starting dealer recv loop" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=trace msg="received accesspoint ping" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="received connection id: OGRiNThhMzMtMDE1My00OWI1LTk5ZmMtMzk3MDRmNjdlNWZhK2RlYWxlcit0Y3A6Ly8wYWNhNTk4Zi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArODE5NUQ0Mjg0QjE3NzhCQzY0Mjk2NDU1QzlERTZFNEJFMzU3MUI5RkY2MTBCMUU2NkJCODk4NzM2OTkxQzZDOQ==" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=trace msg="received accesspoint pong ack" Feb 20 13:43:30 volumio-242 go-librespot[1384]: time="2025-02-20T13:43:30+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 20 13:43:31 volumio-242 volumio[1200]: info: Adding plugin bluetooth to MyMusic Plugins Feb 20 13:43:31 volumio-242 volumio[1200]: info: Adding plugin multiroom to MyMusic Plugins Feb 20 13:43:31 volumio-242 volumio[1200]: info: Adding plugin metavolumio to MyMusic Plugins Feb 20 13:43:31 volumio-242 volumio[1200]: info: Adding plugin cd_controller to MyMusic Plugins Feb 20 13:43:31 volumio-242 volumio[1200]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 20 13:43:31 volumio-242 volumio[1200]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:31 volumio-242 volumio[1200]: info: Starting MyVolumio Remote Streaming Endpoints Feb 20 13:43:31 volumio-242 volumio[1200]: info: MyVolumio login type: Token Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 20 13:43:31 volumio-242 volumio[1200]: info: Starting Streaming Service Transparent Proxy Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 20 13:43:31 volumio-242 volumio[1200]: info: Streaming services startup Feb 20 13:43:31 volumio-242 volumio[1200]: info: Starting Streaming Daemon Feb 20 13:43:31 volumio-242 sudo[1530]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 20 13:43:31 volumio-242 sudo[1530]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:31 volumio-242 volumio[1200]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 20 13:43:31 volumio-242 sudo[1530]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:31 volumio-242 volumio[1200]: verbose: New Socket.io Connection to 192.168.50.218 from 192.168.50.99 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Feb 20 13:43:31 volumio-242 volumio[1200]: error: Cannot start Volumio Streaming Daemon Feb 20 13:43:31 volumio-242 volumio[1200]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 20 13:43:31 volumio-242 volumio[1200]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetVisibleSources Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:31 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:31 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 20 13:43:31 volumio-242 volumio[1200]: info: Received Get System Info Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 13:43:31 volumio-242 volumio[1200]: info: Discovery: Getting this device information Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:31 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 13:43:31 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:31 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:31 volumio-242 volumio[1200]: info: Listing playlists Feb 20 13:43:32 volumio-242 volumio[1200]: STREAMING PROXY: Starting server on port 3245 Feb 20 13:43:32 volumio-242 volumio[1200]: Node JS runtime: 14 Feb 20 13:43:32 volumio-242 volumio[1200]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 20 13:43:32 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 20 13:43:32 volumio-242 volumio[1200]: info: Getting Spotify volume Feb 20 13:43:32 volumio-242 volumio[1200]: info: Spotify volume: 100 Feb 20 13:43:32 volumio-242 volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 20 13:43:32 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:32 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:32 volumio-242 volumio[1200]: info: MyVolumio token set successfully Feb 20 13:43:32 volumio-242 volumio[1200]: info: MYVOLUMIO: Adding device Feb 20 13:43:32 volumio-242 volumio[1200]: info: MYVOLUMIO: Evaluating Server Feb 20 13:43:33 volumio-242 volumio[1200]: info: MyVolumio status changed Feb 20 13:43:33 volumio-242 volumio[1200]: info: Streaming services startup Feb 20 13:43:33 volumio-242 volumio[1200]: info: Starting Streaming Daemon Feb 20 13:43:33 volumio-242 volumio[1200]: info: Removing browser output: myVolumio user plan is not superstar Feb 20 13:43:33 volumio-242 volumio[1200]: info: Removing audio output: Feb 20 13:43:33 volumio-242 volumio[1200]: info: Stoppping Tunnel 1 Feb 20 13:43:33 volumio-242 sudo[1555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 20 13:43:33 volumio-242 sudo[1555]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:33 volumio-242 sudo[1558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 20 13:43:33 volumio-242 sudo[1558]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:33 volumio-242 sudo[1555]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:33 volumio-242 volumio[1200]: error: Cannot start Volumio Streaming Daemon Feb 20 13:43:33 volumio-242 volumio[1200]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 20 13:43:33 volumio-242 volumio[1200]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 20 13:43:33 volumio-242 sudo[1558]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:33 volumio-242 volumio[1200]: info: Remote SSH Stopped Feb 20 13:43:33 volumio-242 volumio[1200]: info: Setting Geolocation for MyVolumio to eu4 Feb 20 13:43:33 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:33 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:33 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:33 volumio-242 volumio[1468]: ...............................................................................++++ Feb 20 13:43:33 volumio-242 volumio[1468]: e is 65537 (0x010001) Feb 20 13:43:33 volumio-242 volumio[1468]: writing RSA key Feb 20 13:43:33 volumio-242 volumio[1200]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 20 13:43:34 volumio-242 volumio-time-update[780]: volumio-time-update-util: Date not found in response Feb 20 13:43:34 volumio-242 volumio-time-update[780]: volumio-time-update-util: Retrying in 5 seconds... Feb 20 13:43:34 volumio-242 volumio[1200]: info: Updating MyVolumio device info Feb 20 13:43:34 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:34 volumio-242 volumio[1200]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 20 13:43:37 volumio-242 volumio[1200]: info: MYVOLUMIO: Adding device Feb 20 13:43:37 volumio-242 volumio[1200]: info: MYVOLUMIO: Evaluating Server Feb 20 13:43:38 volumio-242 volumio[1200]: info: Setting Geolocation for MyVolumio to eu7 Feb 20 13:43:38 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:38 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:38 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:38 volumio-242 volumio[1200]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 20 13:43:39 volumio-242 volumio[1200]: info: Updating MyVolumio device info Feb 20 13:43:39 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:39 volumio-242 volumio-time-update[780]: volumio-time-update-util: Fetching time from Volumio... Feb 20 13:43:39 volumio-242 volumio-time-update[780]: volumio-time-update-util: Setting system time to: 2025-02-20 13:43:39 Feb 20 13:43:39 volumio-242 sudo[1601]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-02-20 13:43:39 Feb 20 13:43:39 volumio-242 sudo[1601]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:43:39 volumio-242 dbus-daemon[790]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.15' (uid=0 pid=1602 comm="timedatectl set-time 2025-02-20 13:43:39 ") Feb 20 13:43:39 volumio-242 systemd[1]: Starting Time & Date Service... Feb 20 13:43:39 volumio-242 dbus-daemon[790]: [system] Successfully activated service 'org.freedesktop.timedate1' Feb 20 13:43:39 volumio-242 systemd[1]: Started Time & Date Service. Feb 20 13:43:39 volumio-242 systemd-timedated[1603]: Changed local time to Thu Feb 20 13:43:39 2025 Feb 20 13:43:39 volumio-242 sudo[1601]: pam_unix(sudo:session): session closed for user root Feb 20 13:43:39 volumio-242 volumio-time-update[780]: volumio-time-update-util: System time updated successfully. Feb 20 13:43:39 volumio-242 systemd[1]: Started Volumio Time Update Utility. Feb 20 13:43:39 volumio-242 systemd[1]: Reached target Multi-User System. Feb 20 13:43:39 volumio-242 systemd[1]: Reached target Graphical Interface. Feb 20 13:43:39 volumio-242 systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 20 13:43:39 volumio-242 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 20 13:43:39 volumio-242 systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 20 13:43:39 volumio-242 systemd[1]: Startup finished in 12.313s (kernel) + 47.146s (userspace) = 59.460s. Feb 20 13:43:39 volumio-242 volumio[1200]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 20 13:43:45 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 20 13:43:45 volumio-242 volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 20 13:43:45 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:45 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:49 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 13:43:49 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:49 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 20 13:43:49 volumio-242 volumio-remote-updater[786]: No test mode Feb 20 13:43:49 volumio-242 volumio-remote-updater[786]: No alpha test mode Feb 20 13:43:49 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 20 13:43:49 volumio-242 volumio[1200]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 20 13:43:49 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 20 13:43:50 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:50 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 20 13:43:50 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 20 13:43:50 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 20 13:43:50 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetBrowseSources Feb 20 13:43:50 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 13:43:51 volumio-242 volumio[1200]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 20 13:43:51 volumio-242 volumio[1200]: info: Completed starting MyVolumio Plugin Feb 20 13:43:51 volumio-242 volumio[1200]: [Metrics] CommandRouter: 34s 362.77ms Feb 20 13:43:51 volumio-242 volumio[1200]: info: CoreCommandRouter::volumiosetStartupVolume Feb 20 13:43:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:43:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:51 volumio-242 volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 20 13:43:51 volumio-242 volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 20 13:43:52 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 20 13:43:52 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 20 13:43:52 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 20 13:43:53 volumio-242 volumiologrotate[784]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Feb 20 13:43:53 volumio-242 volumiologrotate[784]: ls: cannot access '242': No such file or directory Feb 20 13:43:54 volumio-242 volumio[1200]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:43:54 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:54 volumio-242 volumio[1200]: info: Restoring Previous Volume level: false false Feb 20 13:43:54 volumio-242 volumio[1200]: info: Volume configurations have been set Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 20 13:43:54 volumio-242 volumio[1200]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC2 HD Mixer: DAC Max Vol: 100 Vol Curve; logarithmic Vol Steps: 2 Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 20 13:43:54 volumio-242 volumio[1200]: info: Disabling external Volume Control Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 20 13:43:54 volumio-242 volumio[1200]: info: Getting Alsa Cards List without I2S DAC Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 20 13:43:54 volumio-242 volumio[1200]: info: VolumeController:: Volume=0 Mute =true Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreStateMachine::pushState Feb 20 13:43:54 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:54 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 20 13:43:58 volumio-242 volumio[1200]: info: BOOT COMPLETED Feb 20 13:43:58 volumio-242 volumio[1200]: info: VolumeController::SetAlsaVolumeNaN Feb 20 13:43:58 volumio-242 volumio[1200]: info: CoreStateMachine::pushState Feb 20 13:43:58 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:43:58 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 13:43:58 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 20 13:43:59 volumio-242 ntpd[965]: Soliciting pool server 194.58.206.148 Feb 20 13:44:00 volumio-242 go-librespot[1384]: time="2025-02-20T13:44:00+01:00" level=trace msg="sent dealer ping" Feb 20 13:44:00 volumio-242 go-librespot[1384]: time="2025-02-20T13:44:00+01:00" level=trace msg="received dealer pong" Feb 20 13:44:02 volumio-242 ntpd[965]: Soliciting pool server 192.36.143.134 Feb 20 13:44:02 volumio-242 ntpd[965]: Soliciting pool server 192.36.143.130 Feb 20 13:44:02 volumio-242 ntpd[965]: Soliciting pool server 194.58.205.148 Feb 20 13:44:02 volumio-242 ntpd[965]: Soliciting pool server 162.159.200.123 Feb 20 13:44:02 volumio-242 ntpd[965]: Soliciting pool server 192.121.108.100 Feb 20 13:44:03 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:44:03 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:44:03 volumio-242 ntpd[965]: Soliciting pool server 193.182.111.13 Feb 20 13:44:03 volumio-242 ntpd[965]: Soliciting pool server 194.58.205.20 Feb 20 13:44:03 volumio-242 ntpd[965]: Soliciting pool server 98.128.230.186 Feb 20 13:44:04 volumio-242 ntpd[965]: Soliciting pool server 194.58.202.20 Feb 20 13:44:04 volumio-242 ntpd[965]: Soliciting pool server 77.239.113.15 Feb 20 13:44:04 volumio-242 ntpd[965]: Soliciting pool server 45.154.255.240 Feb 20 13:44:05 volumio-242 ntpd[965]: Soliciting pool server 150.241.82.187 Feb 20 13:44:05 volumio-242 ntpd[965]: Soliciting pool server 2001:678:8::123 Feb 20 13:44:09 volumio-242 systemd[1]: systemd-timedated.service: Succeeded. Feb 20 13:44:10 volumio-242 ntpd[965]: receive: Unexpected origin timestamp 0xeb61a219.f17dac3b does not match aorg 0000000000.00000000 from server@77.239.113.15 xmt 0xeb61a21a.b2c43430 Feb 20 13:44:26 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 13:44:26 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 13:44:26 volumio-242 volumio[1200]: info: Discovery: Getting this device information Feb 20 13:44:26 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:44:26 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:44:26 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 13:44:26 volumio-242 volumio[1200]: verbose: New Socket.io Connection to 192.168.50.218:3000 from 192.168.50.227 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Feb 20 13:44:26 volumio-242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:44:26 volumio-242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:44:26 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 20 13:44:26 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 20 13:44:31 volumio-242 go-librespot[1384]: time="2025-02-20T13:44:31+01:00" level=trace msg="sent dealer ping" Feb 20 13:44:31 volumio-242 go-librespot[1384]: time="2025-02-20T13:44:31+01:00" level=trace msg="received dealer pong" Feb 20 13:44:32 volumio-242 volumio[1200]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 13:44:32 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 20 13:44:32 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 20 13:44:32 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 20 13:44:32 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Feb 20 13:44:32 volumio-242 volumio[1200]: info: Received Get System Version Feb 20 13:44:32 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 13:44:36 volumio-242 nmbd[900]: [2025/02/20 13:44:36.215420, 0] ../source3/libsmb/nmblib.c:917(send_udp) Feb 20 13:44:36 volumio-242 nmbd[900]: Packet send failed to 169.254.255.255(138) ERRNO=Network is unreachable Feb 20 13:44:51 volumio-242 volumio[1200]: info: CALLMETHOD: system_controller system saveGeneralSettings [object Object] Feb 20 13:44:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Feb 20 13:44:51 volumio-242 volumio[1200]: info: System name has changed, restarting Shairport Sync Feb 20 13:44:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 13:44:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:44:51 volumio-242 volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 20 13:44:51 volumio-242 volumio[1200]: info: Updating MyVolumio device info Feb 20 13:44:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:44:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:44:51 volumio-242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 13:44:51 volumio-242 volumio[1200]: info: Discovery: Restarting Advertising due to device name change Feb 20 13:44:51 volumio-242 sudo[1815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Feb 20 13:44:51 volumio-242 sudo[1815]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:44:51 volumio-242 sudo[1815]: pam_unix(sudo:session): session closed for user root Feb 20 13:44:51 volumio-242 volumio[1200]: info: Starting Shairport Sync Feb 20 13:44:51 volumio-242 systemd[1]: upmpdcli.service: Succeeded. Feb 20 13:44:51 volumio-242 sudo[1818]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Feb 20 13:44:51 volumio-242 sudo[1818]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:44:51 volumio-242 sudo[1818]: pam_unix(sudo:session): session closed for user root Feb 20 13:44:51 volumio-242 volumio[1200]: info: Permissions for /etc/hosts set Feb 20 13:44:51 volumio-242 sudo[1821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 20 13:44:51 volumio-242 sudo[1821]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:44:51 volumio-242 volumio[1200]: info: Hostname now is volumio242 Feb 20 13:44:51 volumio-242 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 20 13:44:51 volumio-242 systemd[1]: shairport-sync.service: Succeeded. Feb 20 13:44:51 volumio-242 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 20 13:44:51 volumio242 sudo[1824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hostname volumio242 Feb 20 13:44:51 volumio242 sudo[1824]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:44:51 volumio242 volumio[1200]: info: New hostname set Feb 20 13:44:51 volumio242 volumio[1200]: info: Permissions for /etc/avahi/services/volumio.service Feb 20 13:44:51 volumio242 volumio[1200]: info: Avahi name changed to volumio242 Feb 20 13:44:51 volumio242 sudo[1824]: pam_unix(sudo:session): session closed for user root Feb 20 13:44:51 volumio242 sudo[1828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /etc/avahi/services/ Feb 20 13:44:51 volumio242 sudo[1828]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 13:44:51 volumio242 sudo[1828]: pam_unix(sudo:session): session closed for user root Feb 20 13:44:51 volumio242 avahi-daemon[799]: Files changed, reloading. Feb 20 13:44:51 volumio242 avahi-daemon[799]: Service group file /services/volumio.service changed, reloading. Feb 20 13:44:51 volumio242 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 20 13:44:51 volumio242 sudo[1821]: pam_unix(sudo:session): session closed for user root Feb 20 13:44:51 volumio242 volumio[1200]: info: Shairport-Sync Started Feb 20 13:44:52 volumio242 volumio[1200]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 20 13:44:52 volumio242 avahi-daemon[799]: Service "Volumio242" (/services/volumio.service) successfully established. Feb 20 13:44:52 volumio242 volumio[1200]: info: Discovery: A device disappeared from network Feb 20 13:44:54 volumio242 volumiologrotate[784]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Feb 20 13:44:54 volumio242 volumiologrotate[784]: ls: cannot access '242': No such file or directory Feb 20 13:44:56 volumio242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 13:44:56 volumio242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 13:44:56 volumio242 volumio[1200]: info: Discovery: Getting this device information Feb 20 13:44:56 volumio242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:44:56 volumio242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:44:56 volumio242 volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 13:44:56 volumio242 volumio[1200]: info: Discovery: Started advertising with name: Volumio242 Feb 20 13:44:57 volumio242 volumio[1200]: verbose: New Socket.io Connection to 192.168.50.218:3000 from 192.168.50.227 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Feb 20 13:44:57 volumio242 volumio[1200]: info: Discovery: adding 47b65369-02b4-47bc-ac44-d2c6125cfe60 Feb 20 13:44:57 volumio242 volumio[1200]: info: Discovery: Found device Volumio242 Feb 20 13:44:57 volumio242 volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 20 13:44:57 volumio242 volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 20 13:44:57 volumio242 volumio[1200]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 13:44:57 volumio242 volumio[1200]: Error: The value NaN is not a number Feb 20 13:44:57 volumio242 volumio[1200]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) Feb 20 13:44:57 volumio242 volumio[1200]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) Feb 20 13:44:57 volumio242 volumio[1200]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:323:25) Feb 20 13:44:57 volumio242 volumio[1200]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10) Feb 20 13:44:57 volumio242 volumio[1200]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12) Feb 20 13:44:57 volumio242 volumio[1200]: at Browser.emit (events.js:315:20) Feb 20 13:44:57 volumio242 volumio[1200]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Feb 20 13:44:57 volumio242 volumio[1200]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7) Feb 20 13:44:57 volumio242 volumio[1200]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5) Feb 20 13:44:57 volumio242 volumio[1200]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21) Feb 20 13:44:57 volumio242 volumio[1200]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Feb 20 13:44:57 volumio242 volumio[1200]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Feb 20 13:44:57 volumio242 volumio[1200]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Feb 20 13:44:57 volumio242 volumio[1200]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 13:44:57 volumio242 sudo[1887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-20 13:43 Feb 20 13:44:57 volumio242 sudo[1887]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"