Dec 13 01:08:00 pi2iis systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 13 01:08:00 pi2iis systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 13 01:08:00 pi2iis systemd[1]: welcome.service: Deactivated successfully. Dec 13 01:08:00 pi2iis systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 13 01:08:00 pi2iis systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 13 01:08:00 pi2iis systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 13 01:08:00 pi2iis systemd[1]: Started nmbd.service - Samba NMB Daemon. Dec 13 01:08:00 pi2iis welcome[1249]: Resolved ip:[1] 192.168.50.9 Dec 13 01:08:00 pi2iis systemd[1]: Starting winbind.service - Samba Winbind Daemon... Dec 13 01:08:00 pi2iis systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 13 01:08:00 pi2iis systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 13 01:08:00 pi2iis ifplugd(eth0)[964]: client: ifup: interface eth0 already configured Dec 13 01:08:00 pi2iis sh[1268]: eth0=eth0 Dec 13 01:08:00 pi2iis ifplugd(eth0)[964]: Program executed successfully. Dec 13 01:08:00 pi2iis volumio-remote-updater[745]: [2025-12-13 01:08:00] [connect] Successful connection Dec 13 01:08:00 pi2iis winbindd[1264]: [2025/12/13 01:08:00.662042, 0] ../../source3/winbindd/winbindd.c:1440(main) Dec 13 01:08:00 pi2iis winbindd[1264]: winbindd version 4.17.8-Raspbian started. Dec 13 01:08:00 pi2iis winbindd[1264]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 13 01:08:00 pi2iis winbindd[1264]: [2025/12/13 01:08:00.678844, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Dec 13 01:08:00 pi2iis winbindd[1264]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 13 01:08:00 pi2iis systemd[1]: Started winbind.service - Samba Winbind Daemon. Dec 13 01:08:00 pi2iis systemd[1]: Starting smbd.service - Samba SMB Daemon... Dec 13 01:08:01 pi2iis smbd[1277]: [2025/12/13 01:08:01.197685, 0] ../../source3/smbd/server.c:1741(main) Dec 13 01:08:01 pi2iis smbd[1277]: smbd version 4.17.8-Raspbian started. Dec 13 01:08:01 pi2iis smbd[1277]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 13 01:08:01 pi2iis volumio[1152]: info: Loading plugin "network"... Dec 13 01:08:01 pi2iis volumio[1152]: info: Refreshing Cached IP Addresses Dec 13 01:08:01 pi2iis sudo[1290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 01:08:01 pi2iis sudo[1290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:01 pi2iis sudo[1290]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:01 pi2iis sudo[1292]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 01:08:01 pi2iis sudo[1292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:01 pi2iis volumio[1152]: info: Loading plugin "services"... Dec 13 01:08:01 pi2iis sudo[1300]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 13 01:08:01 pi2iis sudo[1292]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:01 pi2iis sudo[1300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:01 pi2iis volumio[1152]: info: Loading plugin "alsa_controller"... Dec 13 01:08:01 pi2iis ntpd[971]: IO: Listen normally on 3 eth0 192.168.50.9:123 Dec 13 01:08:01 pi2iis ntpd[971]: IO: new interface(s) found: waking up resolver Dec 13 01:08:01 pi2iis ntpd[971]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 13 01:08:01 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 01:08:01 pi2iis volumio[1152]: info: Loading plugin "wizard"... Dec 13 01:08:01 pi2iis volumio[1152]: info: Loading plugin "networkfs"... Dec 13 01:08:01 pi2iis ntpd[971]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 13 01:08:01 pi2iis ntpd[971]: DNS: Pool taking: 192.36.143.130 Dec 13 01:08:01 pi2iis ntpd[971]: DNS: Pool taking: 194.58.206.148 Dec 13 01:08:01 pi2iis ntpd[971]: DNS: Pool taking: 194.58.204.148 Dec 13 01:08:01 pi2iis ntpd[971]: DNS: Pool taking: 172.232.157.27 Dec 13 01:08:01 pi2iis ntpd[971]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Dec 13 01:08:01 pi2iis volumio[1152]: info: Starting Udev Watcher for removable devices Dec 13 01:08:01 pi2iis sudo[1324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Pseudonym,password=1NASVERid,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.50.108/sonic /mnt/NAS/SONIC Dec 13 01:08:01 pi2iis sudo[1324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:01 pi2iis volumio[1152]: info: Ignoring mount for partition: boot Dec 13 01:08:01 pi2iis volumio[1152]: info: Ignoring mount for partition: volumio Dec 13 01:08:01 pi2iis volumio[1152]: info: Ignoring mount for partition: volumio_data Dec 13 01:08:01 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 13 01:08:01 pi2iis volumio[1152]: info: Loading plugin "volumio_command_line_client"... Dec 13 01:08:02 pi2iis volumio[1152]: info: Loading plugin "upnp"... Dec 13 01:08:02 pi2iis volumio[1152]: info: [1765584482054] Starting Upmpd Daemon Dec 13 01:08:02 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 13 01:08:02 pi2iis volumio[1152]: info: Loading plugin "my_music"... Dec 13 01:08:02 pi2iis kernel: netfs: FS-Cache loaded Dec 13 01:08:02 pi2iis volumio[1152]: info: Loading plugin "mpd"... Dec 13 01:08:02 pi2iis systemd[1]: Started smbd.service - Samba SMB Daemon. Dec 13 01:08:02 pi2iis systemd[1]: Reached target multi-user.target - Multi-User System. Dec 13 01:08:02 pi2iis systemd[1]: Reached target graphical.target - Graphical Interface. Dec 13 01:08:02 pi2iis kernel: Key type cifs.spnego registered Dec 13 01:08:02 pi2iis kernel: Key type cifs.idmap registered Dec 13 01:08:02 pi2iis kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Dec 13 01:08:02 pi2iis kernel: CIFS: Attempting to mount //192.168.50.108/sonic Dec 13 01:08:02 pi2iis systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Dec 13 01:08:02 pi2iis systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Dec 13 01:08:02 pi2iis systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Dec 13 01:08:02 pi2iis systemd[1]: Startup finished in 12.946s (kernel) + 18.400s (userspace) = 31.346s. Dec 13 01:08:02 pi2iis ntpd[971]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 13 01:08:02 pi2iis volumio[1152]: info: Loading plugin "upnp_browser"... Dec 13 01:08:02 pi2iis ntpd[971]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 193.182.111.13 Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 194.58.204.20 Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 162.159.200.1 Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 45.83.221.52 Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 2a03:8600::cc Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 2001:9b1:9bd0::aa Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 2a01:3f7:2:2::1 Dec 13 01:08:02 pi2iis ntpd[971]: DNS: Pool taking: 2a0e:dc0:2:6597::1 Dec 13 01:08:02 pi2iis ntpd[971]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Dec 13 01:08:03 pi2iis systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Dec 13 01:08:03 pi2iis systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 13 01:08:03 pi2iis systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 13 01:08:03 pi2iis upmpdcli[1353]: Could not open config: /tmp/upmpdcli.conf Dec 13 01:08:03 pi2iis systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 13 01:08:03 pi2iis systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 13 01:08:03 pi2iis ntpd[971]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 13 01:08:03 pi2iis volumio[1152]: info: Starting UPNP Browser Dec 13 01:08:03 pi2iis volumio[1152]: info: Loading plugin "alarm-clock"... Dec 13 01:08:03 pi2iis ntpd[971]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 13 01:08:03 pi2iis ntpd[971]: DNS: Pool taking: 192.36.143.134 Dec 13 01:08:03 pi2iis ntpd[971]: DNS: Pool taking: 194.58.203.148 Dec 13 01:08:03 pi2iis ntpd[971]: DNS: Pool taking: 194.58.205.148 Dec 13 01:08:03 pi2iis ntpd[971]: DNS: Pool taking: 85.24.237.71 Dec 13 01:08:03 pi2iis ntpd[971]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Dec 13 01:08:04 pi2iis volumio[1152]: info: Loading plugin "airplay_emulation"... Dec 13 01:08:04 pi2iis volumio[1152]: info: Starting Shairport Sync Dec 13 01:08:04 pi2iis volumio[1152]: info: Loading plugin "last_100"... Dec 13 01:08:04 pi2iis volumio[1152]: info: Loading plugin "webradio"... Dec 13 01:08:04 pi2iis sudo[1300]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:04 pi2iis volumio[1152]: info: Loading plugin "i2s_dacs"... Dec 13 01:08:04 pi2iis volumio[1152]: info: Loading plugin "volumiodiscovery"... Dec 13 01:08:04 pi2iis volumio[1152]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 13 01:08:04 pi2iis volumio[1152]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 01:08:04 pi2iis volumio[1152]: *** WARNING *** For more information see Dec 13 01:08:04 pi2iis volumio[1152]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 13 01:08:04 pi2iis volumio[1152]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 01:08:04 pi2iis volumio[1152]: *** WARNING *** For more information see Dec 13 01:08:04 pi2iis node[1152]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 13 01:08:04 pi2iis node[1152]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 01:08:04 pi2iis node[1152]: *** WARNING *** For more information see Dec 13 01:08:04 pi2iis node[1152]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 13 01:08:04 pi2iis node[1152]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 01:08:04 pi2iis node[1152]: *** WARNING *** For more information see Dec 13 01:08:04 pi2iis volumio[1152]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 13 01:08:04 pi2iis volumio[1152]: info: Discovery: Started advertising with name: Pi2IIS Dec 13 01:08:04 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 13 01:08:04 pi2iis volumio[1152]: info: Loading plugin "spop"... Dec 13 01:08:04 pi2iis ntpd[971]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 13 01:08:04 pi2iis ntpd[971]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 13 01:08:04 pi2iis ntpd[971]: DNS: Pool skipping: 192.36.143.134 Dec 13 01:08:04 pi2iis ntpd[971]: DNS: Pool taking: 194.58.205.20 Dec 13 01:08:04 pi2iis ntpd[971]: DNS: Pool taking: 98.128.175.45 Dec 13 01:08:04 pi2iis ntpd[971]: DNS: Pool taking: 155.4.55.243 Dec 13 01:08:04 pi2iis ntpd[971]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Dec 13 01:08:06 pi2iis volumio[1152]: info: Loading plugin "outputs"... Dec 13 01:08:06 pi2iis volumio[1152]: info: Loading plugin "albumart"... Dec 13 01:08:06 pi2iis volumio[1152]: info: Plugin example_plugin is not enabled Dec 13 01:08:06 pi2iis volumio[1152]: info: Loading plugin "inputs"... Dec 13 01:08:06 pi2iis volumio[1152]: info: Loading plugin "updater_comm"... Dec 13 01:08:06 pi2iis volumio[1152]: info: Plugin mpdemulation is not enabled Dec 13 01:08:06 pi2iis volumio[1152]: info: Loading plugin "rest_api"... Dec 13 01:08:06 pi2iis volumio[1152]: info: Loading plugin "websocket"... Dec 13 01:08:06 pi2iis volumio[1152]: info: Starting Socket.io Server version 1.7.4 Dec 13 01:08:06 pi2iis volumio[1152]: info: Loading plugin "fusiondsp"... Dec 13 01:08:07 pi2iis sudo[1324]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:07 pi2iis volumio[1373]: Forking 3 albumart workers Dec 13 01:08:07 pi2iis volumio[1152]: info: Applying required configuration parameters for plugin fusiondsp Dec 13 01:08:42 pi2iis ntpd[971]: CLOCK: time stepped by 35.201594 Dec 13 01:08:42 pi2iis ntpd[971]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 13 01:08:43 pi2iis volumio[1152]: info: Loading plugin "scheduledrestart"... Dec 13 01:08:44 pi2iis volumio[1152]: info: Applying required configuration parameters for plugin scheduledrestart Dec 13 01:08:44 pi2iis volumio[1152]: info: Loading i18n strings for locale sv Dec 13 01:08:44 pi2iis volumio[1152]: Updating browse sources language Dec 13 01:08:44 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::initPlayerControls Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 13 01:08:46 pi2iis volumio[1152]: Express server listening on port 3000 Dec 13 01:08:46 pi2iis volumio[1152]: [Metrics] WebUI: 14s 364.16ms Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreStateMachine::resetVolumioState Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreStateMachine::getcurrentVolume Dec 13 01:08:46 pi2iis volumio[1152]: info: CoreCommandRouter::volumioRetrievevolume Dec 13 01:08:47 pi2iis volumio[1152]: info: Volumio Network Manager: Network status updated: 1 Dec 13 01:08:47 pi2iis volumio[1385]: Starting albumart workers Dec 13 01:08:47 pi2iis volumio[1152]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 13 01:08:47 pi2iis volumio[1384]: Starting albumart workers Dec 13 01:08:47 pi2iis volumio[1386]: Starting albumart workers Dec 13 01:08:47 pi2iis sudo[1435]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 01:08:47 pi2iis sudo[1435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:47 pi2iis sudo[1435]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:47 pi2iis sudo[1437]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 01:08:47 pi2iis sudo[1437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:47 pi2iis sudo[1437]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:48 pi2iis volumio[1152]: verbose: New Socket.io Connection to 192.168.50.9 from 192.168.50.43 UA: Mozilla/5.0 (Linux; Android 16; SM-A546B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 13 01:08:48 pi2iis volumio[1152]: info: VolumeController:: Volume=undefined Mute =false Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreStateMachine::pushState Dec 13 01:08:48 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreCommandRouter::volumioPushState Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreStateMachine::updateTrackBlock Dec 13 01:08:48 pi2iis volumio[1152]: info: CorePlayQueue::getTrackBlock Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreCommandRouter::volumioRetrievevolume Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:48 pi2iis volumio[1152]: info: Reloading queue from file Dec 13 01:08:48 pi2iis volumio[1152]: verbose: New Socket.io Connection to 192.168.50.9:3000 from 192.168.50.107 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreStateMachine::setRepeat null single undefined Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreStateMachine::pushState Dec 13 01:08:48 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreCommandRouter::volumioPushState Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreStateMachine::setRandom null Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreStateMachine::pushState Dec 13 01:08:48 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:48 pi2iis volumio[1152]: info: CoreCommandRouter::volumioPushState Dec 13 01:08:48 pi2iis volumio[1152]: info: Setting Device type: Raspberry PI Dec 13 01:08:48 pi2iis volumio[1152]: verbose: New Socket.io Connection to 192.168.50.9 from 192.168.50.43 UA: Mozilla/5.0 (Linux; Android 16; SM-A546B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 13 01:08:48 pi2iis volumio[1152]: info: Completed loading Core Plugins Dec 13 01:08:48 pi2iis volumio[1152]: info: Preparing to generate the ALSA configuration file Dec 13 01:08:48 pi2iis volumio[1152]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 13 01:08:48 pi2iis volumio[1152]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 13 01:08:48 pi2iis volumio[1152]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03111 Dec 13 01:08:48 pi2iis volumio[1152]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 13 01:08:48 pi2iis volumio[1152]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Dec 13 01:08:48 pi2iis volumio[1152]: info: Reading ALSA contributions from plugins. Dec 13 01:08:48 pi2iis volumio[1152]: verbose: New Socket.io Connection to 192.168.50.9:3000 from 192.168.50.107 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: adding 6b823da1-ff7a-4a9c-8efe-582264ea08a1 Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: Found device Pi2AES Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: Connecting to remote: 192.168.50.107 Dec 13 01:08:49 pi2iis volumio[1152]: info: VolumeController:: Volume=undefined Mute =false Dec 13 01:08:49 pi2iis volumio[1152]: info: CoreStateMachine::pushState Dec 13 01:08:49 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:49 pi2iis volumio[1152]: info: CoreCommandRouter::volumioPushState Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: adding 4d31b383-105d-4113-a81e-da6ff9c16703 Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: Found device Pi2IIS Dec 13 01:08:49 pi2iis volumio[1152]: info: CoreCommandRouter::volumioGetState Dec 13 01:08:49 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:49 pi2iis sudo[1454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 13 01:08:49 pi2iis sudo[1454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:49 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: this is already registered, 4d31b383-105d-4113-a81e-da6ff9c16703 Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: Found device Pi2IIS Dec 13 01:08:49 pi2iis volumio[1152]: info: CoreCommandRouter::volumioGetState Dec 13 01:08:49 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:49 pi2iis volumio[1152]: info: Discovery: Connected to remote: 192.168.50.107 Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::volumioGetState Dec 13 01:08:50 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:50 pi2iis volumio[1152]: info: Asound.conf file unchanged, so no further update is needed Dec 13 01:08:50 pi2iis volumio[1152]: info: Output device has changed, restarting MPD Dec 13 01:08:50 pi2iis volumio[1152]: info: Output device has changed, restarting Shairport Sync Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:50 pi2iis sudo[1462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 13 01:08:50 pi2iis sudo[1462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:50 pi2iis sudo[1460]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 13 01:08:50 pi2iis sudo[1460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:50 pi2iis sudo[1460]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:50 pi2iis volumio[1152]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 01:08:50 pi2iis volumio[1152]: info: ___________ START PLUGINS ___________ Dec 13 01:08:50 pi2iis volumio[1152]: info: ControllerMpd::onStart: Initializing MPD Dec 13 01:08:50 pi2iis volumio[1152]: info: Creating MPD Configuration file Dec 13 01:08:50 pi2iis systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 13 01:08:50 pi2iis systemd[1]: Starting mpd.service - Music Player Daemon... Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 13 01:08:50 pi2iis volumio[1152]: info: [1765584530530] CoreMusicLibrary::Adding element Mediaservrar Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 01:08:50 pi2iis sudo[1486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 13 01:08:50 pi2iis sudo[1486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:50 pi2iis volumio[1152]: info: UPNP Browser: Client initialized successfully Dec 13 01:08:50 pi2iis sudo[1478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 13 01:08:50 pi2iis sudo[1484]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 13 01:08:50 pi2iis sudo[1484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 13 01:08:50 pi2iis sudo[1484]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:50 pi2iis sudo[1478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:50 pi2iis systemd[1]: mpd.service: Deactivated successfully. Dec 13 01:08:50 pi2iis systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 13 01:08:50 pi2iis sudo[1478]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:50 pi2iis systemd[1]: mpd.socket: Deactivated successfully. Dec 13 01:08:50 pi2iis systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 13 01:08:50 pi2iis systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 13 01:08:50 pi2iis systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 13 01:08:50 pi2iis systemd[1]: Starting mpd.service - Music Player Daemon... Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:50 pi2iis volumio[1152]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:50 pi2iis sudo[1491]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 13 01:08:50 pi2iis sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 13 01:08:50 pi2iis sudo[1499]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 13 01:08:50 pi2iis sudo[1491]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:50 pi2iis volumio[1152]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 13 01:08:50 pi2iis volumio-remote-updater[745]: [2025-12-13 01:08:50] [connect] Successful connection Dec 13 01:08:50 pi2iis volumio[1152]: info: [1765584530858] CoreMusicLibrary::Adding element Last_100 Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 13 01:08:50 pi2iis volumio[1152]: info: [1765584530879] CoreMusicLibrary::Adding element Webradio Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 01:08:50 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 01:08:50 pi2iis volumio[1152]: info: Initializing BBC Radios Dec 13 01:08:51 pi2iis systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 13 01:08:51 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 01:08:51 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:51 pi2iis volumio[1152]: info: Creating Spotify config file Dec 13 01:08:51 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:51 pi2iis volumio[1152]: info: FusionDsp - CamillaDSP binary found. Dec 13 01:08:51 pi2iis volumio[1152]: info: Loading i18n strings for locale sv Dec 13 01:08:51 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 13 01:08:51 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:51 pi2iis volumio[1152]: info: FusionDsp - mixtype--------------------- undefined Dec 13 01:08:51 pi2iis volumio[1152]: info: Scheduling reboots with hours: 4, minutes: 0 in timezone: Europe/Stockholm Dec 13 01:08:51 pi2iis volumio[1152]: info: Scheduling job with cron expression: 0 0 4 * * 0 Dec 13 01:08:51 pi2iis volumio[1152]: info: Scheduling job with cron expression: 0 0 4 * * 1 Dec 13 01:08:51 pi2iis volumio[1152]: info: Scheduling job with cron expression: 0 0 4 * * 2 Dec 13 01:08:52 pi2iis volumio[1152]: info: Scheduling job with cron expression: 0 0 4 * * 3 Dec 13 01:08:52 pi2iis volumio[1152]: info: Scheduling job with cron expression: 0 0 4 * * 4 Dec 13 01:08:52 pi2iis volumio[1152]: info: Scheduling job with cron expression: 0 0 4 * * 5 Dec 13 01:08:52 pi2iis volumio[1152]: info: Scheduling job with cron expression: 0 0 4 * * 6 Dec 13 01:08:52 pi2iis volumio[1152]: info: Volumio Calling Home Dec 13 01:08:52 pi2iis volumio[1152]: info: Preparing to generate the ALSA configuration file Dec 13 01:08:53 pi2iis systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 13 01:08:54 pi2iis systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 13 01:08:54 pi2iis systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 13 01:08:54 pi2iis systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 13 01:08:54 pi2iis sudo[1454]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:54 pi2iis volumio[1152]: info: camilladsp service started and running in background, instance 1 Dec 13 01:08:54 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:54 pi2iis volumio[1152]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Dec 13 01:08:54 pi2iis sudo[1544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Dec 13 01:08:54 pi2iis sudo[1544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:55 pi2iis volumio[1152]: info: FusionDsp loaded Dec 13 01:08:55 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 01:08:55 pi2iis volumio[1152]: error: FusionDsp - Socket connection not established Dec 13 01:08:55 pi2iis volumio[1152]: info: FusionDsp - Reporting Fusion DSP Enabled Dec 13 01:08:55 pi2iis volumio[1152]: info: Adding Signal Path Element [object Object] Dec 13 01:08:55 pi2iis volumio[1152]: info: Adding fusiondspeq DSP Signal Path Element Dec 13 01:08:55 pi2iis volumio[1152]: info: FusionDsp - ---- installed callbackRead Dec 13 01:08:55 pi2iis volumio[1152]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 13 01:08:55 pi2iis mpd[1501]: 2025-12-13T01:08:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 13 01:08:55 pi2iis systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Dec 13 01:08:55 pi2iis sudo[1544]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:55 pi2iis volumio[1152]: info: FusionDsp - Nulleq applied Dec 13 01:08:55 pi2iis volumio[1152]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Dec 13 01:08:55 pi2iis volumio[1152]: info: Reading ALSA contributions from plugins. Dec 13 01:08:55 pi2iis volumio[1152]: info: MPD Permissions set Dec 13 01:08:55 pi2iis volumio[1152]: info: MPD Permissions set Dec 13 01:08:55 pi2iis volumio[1152]: info: Upmpdcli Daemon Started Dec 13 01:08:56 pi2iis volumio[1152]: info: Volumio called home Dec 13 01:08:56 pi2iis volumio[1152]: info: Spotify config file written Dec 13 01:08:56 pi2iis sudo[1553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 13 01:08:56 pi2iis sudo[1553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:56 pi2iis systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 13 01:08:56 pi2iis systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 13 01:08:56 pi2iis systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 13 01:08:56 pi2iis systemd[1]: Started mpd.service - Music Player Daemon. Dec 13 01:08:56 pi2iis go-librespot[1555]: go-librespot daemon starting... Dec 13 01:08:56 pi2iis sudo[1462]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:56 pi2iis sudo[1486]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:56 pi2iis sudo[1553]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:56 pi2iis volumio[1152]: verbose: New Socket.io Connection to 192.168.50.9 from 192.168.50.43 UA: Mozilla/5.0 (Linux; Android 16; SM-A546B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Dec 13 01:08:56 pi2iis volumio[1152]: error: FusionDsp - Reload WebSocket error: [object Object] Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis go-librespot[1558]: time="2025-12-13T01:08:56+01:00" level=info msg="running go-librespot 0.4.0" Dec 13 01:08:56 pi2iis go-librespot[1558]: time="2025-12-13T01:08:56+01:00" level=debug msg="app state loaded" Dec 13 01:08:56 pi2iis go-librespot[1558]: time="2025-12-13T01:08:56+01:00" level=debug msg="stored credentials not found" Dec 13 01:08:56 pi2iis go-librespot[1558]: time="2025-12-13T01:08:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:56 pi2iis volumio[1152]: info: No need to fix Spotify hosts Dec 13 01:08:57 pi2iis volumio[1152]: Upnp client error: Error: This socket has been ended by the other party Dec 13 01:08:57 pi2iis volumio[1152]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 13 01:08:57 pi2iis go-librespot[1558]: time="2025-12-13T01:08:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 13 01:08:57 pi2iis go-librespot[1558]: time="2025-12-13T01:08:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 13 01:08:57 pi2iis go-librespot[1558]: time="2025-12-13T01:08:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 13 01:08:57 pi2iis go-librespot[1558]: time="2025-12-13T01:08:57+01:00" level=info msg="zeroconf server listening on port 33621" Dec 13 01:08:57 pi2iis volumio[1152]: info: Completed starting Core Plugins Dec 13 01:08:57 pi2iis volumio[1152]: info: ------------------------------------------- Dec 13 01:08:57 pi2iis volumio[1152]: info: ----- MyVolumio plugins startup ---- Dec 13 01:08:57 pi2iis volumio[1152]: info: ------------------------------------------- Dec 13 01:08:57 pi2iis volumio[1152]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 13 01:08:57 pi2iis volumio[1152]: 0+0 records in Dec 13 01:08:57 pi2iis volumio[1152]: 0+0 records out Dec 13 01:08:57 pi2iis volumio[1152]: 0 bytes copied, 0.0102558 s, 0.0 kB/s Dec 13 01:08:57 pi2iis volumio[1152]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 13 01:08:58 pi2iis volumio[1152]: error: MPD error: The expression evaluated to a falsy value: Dec 13 01:08:58 pi2iis volumio[1152]: assert.ok(self.idling) Dec 13 01:08:58 pi2iis volumio[1152]: error: The expression evaluated to a falsy value: Dec 13 01:08:58 pi2iis volumio[1152]: assert.ok(self.idling) Dec 13 01:08:58 pi2iis volumio[1152]: info: MPD running with PID1501 Dec 13 01:08:58 pi2iis volumio[1152]: ,establishing connection Dec 13 01:08:58 pi2iis volumio[1152]: info: Starting Shairport Sync Dec 13 01:08:58 pi2iis volumio[1152]: info: Starting Shairport Sync Dec 13 01:08:58 pi2iis volumio[1152]: info: Starting Shairport Sync Dec 13 01:08:58 pi2iis volumio[1152]: error: updateQueue error: null Dec 13 01:08:58 pi2iis sudo[1599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 01:08:58 pi2iis sudo[1599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:58 pi2iis sudo[1603]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 01:08:58 pi2iis sudo[1603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:58 pi2iis sudo[1601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 01:08:58 pi2iis sudo[1601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:58 pi2iis volumio[1152]: info: Asound.conf file unchanged, so no further update is needed Dec 13 01:08:58 pi2iis volumio[1152]: info: Output device has changed, restarting MPD Dec 13 01:08:58 pi2iis systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 13 01:08:58 pi2iis systemd[1]: shairport-sync.service: Deactivated successfully. Dec 13 01:08:58 pi2iis systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 01:08:58 pi2iis systemd[1]: shairport-sync.service: Consumed 1.654s CPU time. Dec 13 01:08:58 pi2iis volumio[1152]: info: Output device has changed, restarting Shairport Sync Dec 13 01:08:58 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:58 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:58 pi2iis sudo[1608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 13 01:08:58 pi2iis sudo[1608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:58 pi2iis systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 01:08:58 pi2iis sudo[1599]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:58 pi2iis sudo[1611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 13 01:08:58 pi2iis sudo[1611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:08:58 pi2iis systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 13 01:08:58 pi2iis sudo[1608]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:58 pi2iis systemd[1]: shairport-sync.service: Deactivated successfully. Dec 13 01:08:58 pi2iis systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 01:08:58 pi2iis systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 01:08:58 pi2iis sudo[1601]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:58 pi2iis sudo[1603]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:58 pi2iis volumio[1152]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 01:08:58 pi2iis volumio[1152]: error: updateQueue error: null Dec 13 01:08:58 pi2iis systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 13 01:08:58 pi2iis volumio[1152]: info: MPD Permissions set Dec 13 01:08:58 pi2iis volumio[1152]: info: Shairport-Sync Started Dec 13 01:08:58 pi2iis volumio[1152]: Error adding Membership: Error: addMembership EINVAL Dec 13 01:08:58 pi2iis volumio[1152]: info: Shairport-Sync Started Dec 13 01:08:58 pi2iis volumio[1152]: info: Shairport-Sync Started Dec 13 01:08:58 pi2iis systemd[1]: mpd.service: Deactivated successfully. Dec 13 01:08:58 pi2iis systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 13 01:08:58 pi2iis systemd[1]: mpd.service: Consumed 4.001s CPU time. Dec 13 01:08:58 pi2iis systemd[1]: mpd.socket: Deactivated successfully. Dec 13 01:08:58 pi2iis systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 13 01:08:58 pi2iis systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 13 01:08:59 pi2iis volumio[1152]: 0+0 records in Dec 13 01:08:59 pi2iis volumio[1152]: 0+0 records out Dec 13 01:08:59 pi2iis volumio[1152]: 0 bytes copied, 0.000119625 s, 0.0 kB/s Dec 13 01:08:59 pi2iis volumio[1152]: error: Upnp client error: Error: read ECONNRESET Dec 13 01:08:59 pi2iis systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 13 01:08:59 pi2iis systemd[1]: Starting mpd.service - Music Player Daemon... Dec 13 01:08:59 pi2iis sudo[1651]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 13 01:08:59 pi2iis sudo[1651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 13 01:08:59 pi2iis sudo[1651]: pam_unix(sudo:session): session closed for user root Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:08:59 pi2iis volumio[1152]: info: CoreCommandRouter::volumioGetState Dec 13 01:08:59 pi2iis volumio[1152]: info: CorePlayQueue::getTrack 0 Dec 13 01:08:59 pi2iis volumio[1152]: info: Starting Shairport Sync Dec 13 01:08:59 pi2iis sudo[1661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 01:09:00 pi2iis sudo[1661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:09:00 pi2iis systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 13 01:09:00 pi2iis systemd[1]: shairport-sync.service: Deactivated successfully. Dec 13 01:09:00 pi2iis systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 01:09:00 pi2iis systemd[1]: shairport-sync.service: Consumed 1.283s CPU time. Dec 13 01:09:00 pi2iis systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 13 01:09:00 pi2iis sudo[1661]: pam_unix(sudo:session): session closed for user root Dec 13 01:09:00 pi2iis volumio[1152]: info: go-librespot daemon successfully initialized Dec 13 01:09:00 pi2iis volumio[1152]: info: Shairport-Sync Started Dec 13 01:09:00 pi2iis sudo[1665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 13 01:09:00 pi2iis sudo[1665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:09:00 pi2iis volumio[1152]: 0+0 records in Dec 13 01:09:00 pi2iis volumio[1152]: 0+0 records out Dec 13 01:09:00 pi2iis volumio[1152]: 0 bytes copied, 0.000133903 s, 0.0 kB/s Dec 13 01:09:00 pi2iis sudo[1679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 13 01:09:00 pi2iis sudo[1679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:09:00 pi2iis mpd[1654]: 2025-12-13T01:09:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 13 01:09:01 pi2iis systemd[1]: Started mpd.service - Music Player Daemon. Dec 13 01:09:01 pi2iis sudo[1611]: pam_unix(sudo:session): session closed for user root Dec 13 01:09:01 pi2iis systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 13 01:09:01 pi2iis mpd_monitor.sh[1692]: MPD Monitor Service: Starting MPD Monitor Service Dec 13 01:09:01 pi2iis sudo[1679]: pam_unix(sudo:session): session closed for user root Dec 13 01:09:01 pi2iis sudo[1665]: pam_unix(sudo:session): session closed for user root Dec 13 01:09:01 pi2iis volumio[1152]: 0+0 records in Dec 13 01:09:01 pi2iis volumio[1152]: 0+0 records out Dec 13 01:09:01 pi2iis volumio[1152]: 0 bytes copied, 0.000120366 s, 0.0 kB/s Dec 13 01:09:01 pi2iis volumio[1152]: info: Successfully started MPD Monitor Dec 13 01:09:01 pi2iis volumio[1152]: info: Successfully started MPD Monitor Dec 13 01:09:01 pi2iis volumio[1152]: error: updateQueue error: null Dec 13 01:09:02 pi2iis volumio[1152]: 0+0 records in Dec 13 01:09:02 pi2iis volumio[1152]: 0+0 records out Dec 13 01:09:02 pi2iis volumio[1152]: 0 bytes copied, 0.0212843 s, 0.0 kB/s Dec 13 01:09:03 pi2iis volumio[1152]: info: Initializing connection to go-librespot Websocket Dec 13 01:09:03 pi2iis go-librespot[1558]: time="2025-12-13T01:09:03+01:00" level=debug msg="new websocket client" Dec 13 01:09:03 pi2iis volumio[1152]: info: Connection to go-librespot Websocket established Dec 13 01:09:03 pi2iis volumio[1152]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 13 01:09:03 pi2iis volumio[1152]: 0+0 records in Dec 13 01:09:03 pi2iis volumio[1152]: 0+0 records out Dec 13 01:09:03 pi2iis volumio[1152]: 0 bytes copied, 0.000117348 s, 0.0 kB/s Dec 13 01:09:05 pi2iis volumio-remote-updater[745]: [2025-12-13 01:09:05] [connect] Successful connection Dec 13 01:09:06 pi2iis sudo[1715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 13 01:09:06 pi2iis sudo[1715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 13 01:09:06 pi2iis systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 13 01:09:06 pi2iis systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 13 01:09:06 pi2iis systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 13 01:09:06 pi2iis systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 13 01:09:06 pi2iis systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 13 01:09:06 pi2iis mpd_monitor.sh[1719]: MPD Monitor Service: Starting MPD Monitor Service Dec 13 01:09:06 pi2iis sudo[1715]: pam_unix(sudo:session): session closed for user root Dec 13 01:09:07 pi2iis systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 13 01:09:07 pi2iis systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 13 01:09:09 pi2iis volumio[1152]: info: Getting Spotify volume Dec 13 01:09:09 pi2iis volumio[1152]: 0+0 records in Dec 13 01:09:09 pi2iis volumio[1152]: 0+0 records out Dec 13 01:09:09 pi2iis volumio[1152]: 0 bytes copied, 0.000117108 s, 0.0 kB/s Dec 13 01:09:10 pi2iis volumio-remote-updater[745]: [2025-12-13 01:09:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765584545 101 Dec 13 01:09:10 pi2iis volumio[1152]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 8 Dec 13 01:09:10 pi2iis volumio[1152]: info: Successfully started MPD Monitor Dec 13 01:09:11 pi2iis volumio[1152]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 13 01:09:12 pi2iis volumio[1152]: 0+0 records in Dec 13 01:09:12 pi2iis volumio[1152]: 0+0 records out Dec 13 01:09:12 pi2iis volumio[1152]: 0 bytes copied, 0.0170882 s, 0.0 kB/s Dec 13 01:09:21 pi2iis volumio[1152]: error: MyVolumio Plugin failed to start in a timely fashion Dec 13 01:09:21 pi2iis volumio[1152]: [Metrics] CommandRouter: 47s 909.19ms Dec 13 01:09:21 pi2iis volumio[1152]: info: CoreCommandRouter::volumiosetStartupVolume Dec 13 01:09:21 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 01:09:21 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:09:21 pi2iis volumio[1152]: info: CoreCommandRouter::Close All Modals sent Dec 13 01:09:21 pi2iis volumio[1152]: info: CoreCommandRouter::Close All Modals sent Dec 13 01:09:31 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 01:09:31 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 01:09:31 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 13 01:09:31 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 13 01:09:31 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 13 01:09:31 pi2iis volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 13 01:09:31 pi2iis volumio[1152]: info: BOOT COMPLETED Dec 13 01:09:45 pi2iis volumio[1152]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Dec 13 01:09:45 pi2iis volumio[1152]: info: FusionDsp - ---- read samplerate from file: 44100 Dec 13 01:09:45 pi2iis volumio[1152]: info: camilladsp service terminated, instance 1 Dec 13 01:09:45 pi2iis volumio[1152]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 13 01:09:45 pi2iis volumio[1152]: info: FusionDsp - Nulleq applied Dec 13 01:09:45 pi2iis volumio[1152]: info: camilladsp service started and running in background, instance 1 Dec 13 01:09:45 pi2iis volumio[1152]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Dec 13 01:09:45 pi2iis volumio[1152]: 2+0 records in Dec 13 01:09:45 pi2iis volumio[1152]: 2+0 records out Dec 13 01:09:45 pi2iis volumio[1152]: 65536 bytes (66 kB, 64 KiB) copied, 0.0173618 s, 3.8 MB/s Dec 13 01:09:45 pi2iis volumio[1152]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 01:09:46 pi2iis volumio[1152]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Dec 13 01:09:46 pi2iis volumio[1152]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Dec 13 01:09:46 pi2iis volumio[1152]: at new NodeError (node:internal/errors:405:5) Dec 13 01:09:46 pi2iis volumio[1152]: at assert (node:internal/assert:14:11) Dec 13 01:09:46 pi2iis volumio[1152]: at internalConnectMultiple (node:net:1118:3) Dec 13 01:09:46 pi2iis volumio[1152]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Dec 13 01:09:46 pi2iis volumio[1152]: at listOnTimeout (node:internal/timers:575:11) Dec 13 01:09:46 pi2iis volumio[1152]: at process.processTimers (node:internal/timers:514:7) { Dec 13 01:09:46 pi2iis volumio[1152]: code: 'ERR_INTERNAL_ASSERTION' Dec 13 01:09:46 pi2iis volumio[1152]: } Dec 13 01:09:46 pi2iis volumio[1152]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 01:09:48 pi2iis sudo[1856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-13 01:08' Dec 13 01:09:48 pi2iis sudo[1856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"