Feb 23 21:39:06 raspi2 ntpd[1129]: CLOCK: time stepped by 610423.651100 Feb 23 21:39:06 raspi2 ntpd[1129]: CLOCK: time changed from 2026-02-16 to 2026-02-23 Feb 23 21:39:06 raspi2 ntpd[1129]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Feb 23 21:39:06 raspi2 systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Feb 23 21:39:06 raspi2 systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Feb 23 21:39:06 raspi2 systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Feb 23 21:39:06 raspi2 systemd[1]: e2scrub_all.service: Deactivated successfully. Feb 23 21:39:06 raspi2 systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Feb 23 21:39:06 raspi2 systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Feb 23 21:39:06 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:06 raspi2 volumio[1483]: info: MYVOLUMIO Environment detected Feb 23 21:39:07 raspi2 volumio[1483]: info: Plugin folders cleanup Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning into folder /volumio/app/plugins/ Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category audio_interface Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category miscellanea Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category music_service Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category plugins.json Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category system_controller Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category user_interface Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning into folder /data/plugins/ Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category audio_interface Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category music_service Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category system_controller Feb 23 21:39:07 raspi2 volumio[1483]: info: Scanning category system_hardware Feb 23 21:39:07 raspi2 systemd[1]: dpkg-db-backup.service: Deactivated successfully. Feb 23 21:39:07 raspi2 systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Feb 23 21:39:07 raspi2 volumio[1483]: info: Plugin folders cleanup completed Feb 23 21:39:07 raspi2 volumio[1483]: info: ------------------------------------------- Feb 23 21:39:07 raspi2 volumio[1483]: info: ----- Core plugins startup ---- Feb 23 21:39:07 raspi2 volumio[1483]: info: ------------------------------------------- Feb 23 21:39:07 raspi2 volumio[1483]: info: Loading plugins from folder /volumio/app/plugins/ Feb 23 21:39:07 raspi2 volumio[1483]: info: Adding plugin upnp to MyMusic Plugins Feb 23 21:39:07 raspi2 volumio[1483]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 23 21:39:07 raspi2 volumio[1483]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 23 21:39:07 raspi2 volumio[1483]: info: Loading plugins from folder /data/plugins/ Feb 23 21:39:07 raspi2 volumio[1483]: info: Loading plugin "system"... Feb 23 21:39:07 raspi2 volumio[1483]: info: Loading plugin "appearance"... Feb 23 21:39:08 raspi2 volumio[1483]: info: Loading plugin "network"... Feb 23 21:39:08 raspi2 volumio[1483]: info: Refreshing Cached IP Addresses Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "services"... Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "volumio5onboarding"... Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "alsa_controller"... Feb 23 21:39:09 raspi2 sudo[1582]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 21:39:09 raspi2 sudo[1584]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 21:39:09 raspi2 sudo[1582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:09 raspi2 sudo[1584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:09 raspi2 sudo[1582]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:09 raspi2 sudo[1584]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:09 raspi2 sudo[1589]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 23 21:39:09 raspi2 sudo[1589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:09 raspi2 sudo[1589]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:09 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "wizard"... Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "networkfs"... Feb 23 21:39:09 raspi2 volumio[1483]: info: Starting Udev Watcher for removable devices Feb 23 21:39:09 raspi2 volumio[1483]: info: Ignoring mount for partition: boot Feb 23 21:39:09 raspi2 volumio[1483]: info: Ignoring mount for partition: volumio Feb 23 21:39:09 raspi2 volumio[1483]: info: Ignoring mount for partition: volumio_data Feb 23 21:39:09 raspi2 volumio[1483]: info: Mounting Device bootfs Feb 23 21:39:09 raspi2 sudo[1625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/bootfs -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Feb 23 21:39:09 raspi2 sudo[1625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:09 raspi2 kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Feb 23 21:39:09 raspi2 kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Feb 23 21:39:09 raspi2 sudo[1625]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:09 raspi2 volumio[1483]: info: Mounting Device rootfs Feb 23 21:39:09 raspi2 sudo[1638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/rootfs -o noatime Feb 23 21:39:09 raspi2 sudo[1638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:09 raspi2 kernel: EXT4-fs (sda2): recovery complete Feb 23 21:39:09 raspi2 kernel: EXT4-fs (sda2): mounted filesystem d6ecfcd5-2703-41bf-9301-10c403b6fb0c r/w with ordered data mode. Quota mode: none. Feb 23 21:39:09 raspi2 sudo[1638]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:09 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "volumio_command_line_client"... Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "upnp"... Feb 23 21:39:09 raspi2 volumio[1483]: info: [1771904349786] Starting Upmpd Daemon Feb 23 21:39:09 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "my_music"... Feb 23 21:39:09 raspi2 volumio[1483]: info: Loading plugin "mpd"... Feb 23 21:39:10 raspi2 volumio[1483]: info: Loading plugin "upnp_browser"... Feb 23 21:39:11 raspi2 volumio[1483]: info: Starting UPNP Browser Feb 23 21:39:11 raspi2 volumio[1483]: info: Loading plugin "alarm-clock"... Feb 23 21:39:11 raspi2 volumio[1483]: info: Loading plugin "airplay_emulation"... Feb 23 21:39:11 raspi2 volumio[1483]: info: Starting Shairport Sync Feb 23 21:39:11 raspi2 volumio[1483]: info: Loading plugin "last_100"... Feb 23 21:39:11 raspi2 volumio[1483]: info: Loading plugin "webradio"... Feb 23 21:39:11 raspi2 volumio[1483]: info: Loading plugin "i2s_dacs"... Feb 23 21:39:11 raspi2 volumio[1483]: info: Loading plugin "volumiodiscovery"... Feb 23 21:39:11 raspi2 volumio[1483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 21:39:11 raspi2 volumio[1483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 21:39:11 raspi2 volumio[1483]: *** WARNING *** For more information see Feb 23 21:39:11 raspi2 volumio[1483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 21:39:11 raspi2 volumio[1483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 21:39:11 raspi2 node[1483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 21:39:11 raspi2 volumio[1483]: *** WARNING *** For more information see Feb 23 21:39:11 raspi2 node[1483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 21:39:11 raspi2 node[1483]: *** WARNING *** For more information see Feb 23 21:39:11 raspi2 node[1483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 21:39:11 raspi2 node[1483]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 21:39:11 raspi2 node[1483]: *** WARNING *** For more information see Feb 23 21:39:11 raspi2 volumio[1483]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 23 21:39:11 raspi2 volumio[1483]: info: Discovery: Started advertising with name: Raspi2 Feb 23 21:39:11 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 21:39:11 raspi2 volumio[1483]: info: Loading plugin "jellyfin"... Feb 23 21:39:12 raspi2 volumio-remote-updater[860]: [2026-02-23 21:39:12] [connect] Successful connection Feb 23 21:39:12 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:13 raspi2 volumio[1483]: info: Loading plugin "outputs"... Feb 23 21:39:13 raspi2 volumio[1483]: info: Loading plugin "albumart"... Feb 23 21:39:13 raspi2 volumio[1483]: info: Plugin example_plugin is not enabled Feb 23 21:39:13 raspi2 volumio[1483]: info: Loading plugin "inputs"... Feb 23 21:39:13 raspi2 volumio[1483]: info: Loading plugin "updater_comm"... Feb 23 21:39:13 raspi2 volumio[1483]: info: Plugin mpdemulation is not enabled Feb 23 21:39:13 raspi2 volumio[1483]: info: Loading plugin "rest_api"... Feb 23 21:39:13 raspi2 volumio[1483]: info: Loading plugin "websocket"... Feb 23 21:39:13 raspi2 volumio[1483]: info: Starting Socket.io Server version 1.7.4 Feb 23 21:39:13 raspi2 volumio[1483]: info: Loading plugin "fusiondsp"... Feb 23 21:39:14 raspi2 volumio[1648]: Forking 3 albumart workers Feb 23 21:39:14 raspi2 volumio[1483]: info: Applying required configuration parameters for plugin fusiondsp Feb 23 21:39:15 raspi2 volumio[1483]: info: Loading plugin "backup_restore"... Feb 23 21:39:16 raspi2 systemd[1]: systemd-fsckd.service: Deactivated successfully. Feb 23 21:39:17 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:17 raspi2 volumio[1483]: info: Applying required configuration parameters for plugin backup_restore Feb 23 21:39:17 raspi2 volumio[1483]: info: Loading plugin "Bluetoothremote"... Feb 23 21:39:18 raspi2 volumio[1483]: info: Applying required configuration parameters for plugin Bluetoothremote Feb 23 21:39:18 raspi2 volumio[1483]: info: Loading plugin "remotepi"... Feb 23 21:39:19 raspi2 volumio[1659]: Starting albumart workers Feb 23 21:39:19 raspi2 volumio[1660]: Starting albumart workers Feb 23 21:39:19 raspi2 volumio[1658]: Starting albumart workers Feb 23 21:39:19 raspi2 volumio[1483]: info: Applying required configuration parameters for plugin remotepi Feb 23 21:39:20 raspi2 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Feb 23 21:39:20 raspi2 tailscaled[856]: LinkChange: major, rebinding: old: interfaces.State{defaultRoute=eth0 ifs={eth0:[192.168.3.16/24]} v4=true v6=false} new: interfaces.State{defaultRoute=eth0 ifs={eth0:[192.168.3.16/24] tailscale0:[100.85.253.93/32]} v4=true v6=false} Feb 23 21:39:20 raspi2 tailscaled[856]: dns: Set: {DefaultResolvers:[100.106.206.11 100.93.223.101 100.118.77.44 1.1.1.1 1.0.0.1 2606:4700:4700::1111 2606:4700:4700::1001 8.8.8.8 8.8.4.4 2001:4860:4860::8888 2001:4860:4860::8844] Routes:{tailbae40e.ts.net.:[] ts.net.:[199.247.155.53 2620:111:8007::53]}+65arpa SearchDomains:[tailbae40e.ts.net.] Hosts:20} Feb 23 21:39:20 raspi2 tailscaled[856]: dns: Resolvercfg: {Routes:{.:[100.106.206.11 100.93.223.101 100.118.77.44 1.1.1.1 1.0.0.1 2606:4700:4700::1111 2606:4700:4700::1001 8.8.8.8 8.8.4.4 2001:4860:4860::8888 2001:4860:4860::8844] ts.net.:[199.247.155.53 2620:111:8007::53]} Hosts:20 LocalDomains:[tailbae40e.ts.net.]+65arpa} Feb 23 21:39:20 raspi2 tailscaled[856]: dns: OScfg: {Nameservers:[100.100.100.100] SearchDomains:[tailbae40e.ts.net.] } Feb 23 21:39:20 raspi2 tailscaled[856]: wgengine: set DNS config again after major link change Feb 23 21:39:20 raspi2 tailscaled[856]: router: portUpdate(port=41641, network=udp6) Feb 23 21:39:20 raspi2 tailscaled[856]: router: portUpdate(port=41641, network=udp4) Feb 23 21:39:20 raspi2 tailscaled[856]: Rebind; defIf="eth0", ips=[192.168.3.16/24] Feb 23 21:39:20 raspi2 tailscaled[856]: magicsock: 1 active derp conns: derp-9=cr19s,wr3s Feb 23 21:39:20 raspi2 tailscaled[856]: post-rebind ping of DERP region 9 okay Feb 23 21:39:20 raspi2 volumio[1483]: info: Loading i18n strings for locale es Feb 23 21:39:20 raspi2 volumio[1483]: error: remotepi: Fetching language file: Error: i18n file complementing the system language not found. Feb 23 21:39:20 raspi2 volumio[1483]: Updating browse sources language Feb 23 21:39:20 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 21:39:20 raspi2 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Feb 23 21:39:20 raspi2 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 21:39:20 raspi2 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 21:39:20 raspi2 upmpdcli[1708]: Could not open config: /tmp/upmpdcli.conf Feb 23 21:39:20 raspi2 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 23 21:39:20 raspi2 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 23 21:39:21 raspi2 tailscaled[856]: magicsock: disco: node [YWVOW] d:007ab2b4eb58646d now using 192.168.100.53:41641 mtu=1360 tx=e4c759e9de47 Feb 23 21:39:21 raspi2 tailscaled[856]: magicsock: disco: node [l2Q3L] d:810ada179b1b0ad2 now using 192.168.100.60:41641 mtu=1360 tx=281190e56add Feb 23 21:39:21 raspi2 tailscaled[856]: logtail: upload succeeded after 1 failures and 32s Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::initPlayerControls Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 21:39:21 raspi2 volumio[1483]: Express server listening on port 3000 Feb 23 21:39:21 raspi2 volumio[1483]: [Metrics] WebUI: 16s 731.07ms Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreStateMachine::resetVolumioState Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreStateMachine::getcurrentVolume Feb 23 21:39:21 raspi2 volumio[1483]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 21:39:22 raspi2 sudo[1720]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 21:39:22 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:22 raspi2 sudo[1720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:22 raspi2 sudo[1722]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 21:39:22 raspi2 sudo[1722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:22 raspi2 volumio[1483]: MPD error: Connection refused Feb 23 21:39:22 raspi2 sudo[1720]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:22 raspi2 sudo[1722]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:22 raspi2 volumio[1483]: MPD error: Connection refused Feb 23 21:39:22 raspi2 volumio[1483]: info: Volumio Network Manager: Network status updated: 1 Feb 23 21:39:22 raspi2 volumio[1483]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 23 21:39:22 raspi2 volumio[1483]: wlan0 Interface doesn't support scanning : Device or resource busy Feb 23 21:39:22 raspi2 volumio[1483]: info: Cannot use regular scanning, forcing with ap-force Feb 23 21:39:22 raspi2 sudo[1742]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 23 21:39:22 raspi2 sudo[1742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:27 raspi2 volumio-remote-updater[860]: [2026-02-23 21:39:27] [connect] Successful connection Feb 23 21:39:27 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:30 raspi2 sudo[1742]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:31 raspi2 volumio[1483]: info: VolumeController:: Volume=79 Mute =false Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreStateMachine::pushState Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioPushState Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreStateMachine::updateTrackBlock Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrackBlock Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:31 raspi2 volumio[1483]: info: Reloading queue from file Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:31 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreStateMachine::setRepeat null single undefined Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreStateMachine::pushState Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioPushState Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreStateMachine::setRandom null Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreStateMachine::pushState Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioPushState Feb 23 21:39:31 raspi2 volumio[1483]: info: Setting Device type: Raspberry PI Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:31 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:31 raspi2 volumio[1483]: info: Completed loading Core Plugins Feb 23 21:39:31 raspi2 volumio[1483]: info: Preparing to generate the ALSA configuration file Feb 23 21:39:31 raspi2 volumio[1483]: info: VolumeController:: Volume=79 Mute =false Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreStateMachine::pushState Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioPushState Feb 23 21:39:31 raspi2 volumio[1483]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 23 21:39:31 raspi2 volumio[1483]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Feb 23 21:39:31 raspi2 volumio[1483]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:31 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:31 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:31 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:31 raspi2 volumio[1483]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 23 21:39:31 raspi2 volumio[1483]: info: Reading ALSA contributions from plugins. Feb 23 21:39:31 raspi2 volumio-remote-updater[860]: [2026-02-23 21:39:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771904367 101 Feb 23 21:39:31 raspi2 volumio[1483]: 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: 1 Feb 23 21:39:31 raspi2 sudo[1776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 21:39:31 raspi2 sudo[1776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:32 raspi2 volumio[1483]: info: Discovery: adding 681a86ee-8311-4198-a64b-b8c501747964 Feb 23 21:39:32 raspi2 volumio[1483]: info: Discovery: Found device Raspi2 Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:32 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:32 raspi2 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:32 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:32 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:32 raspi2 volumio[1483]: info: Discovery: this is already registered, 681a86ee-8311-4198-a64b-b8c501747964 Feb 23 21:39:32 raspi2 volumio[1483]: info: Discovery: Found device Raspi2 Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:32 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:32 raspi2 volumio[1483]: verbose: New Socket.io Connection to 192.168.3.16:3000 from 192.168.3.6 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 2 Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 23 21:39:32 raspi2 volumio[1483]: info: Asound.conf file unchanged, so no further update is needed Feb 23 21:39:32 raspi2 volumio[1483]: info: Output device has changed, restarting MPD Feb 23 21:39:32 raspi2 volumio[1483]: info: Output device has changed, restarting Shairport Sync Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:32 raspi2 sudo[1793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 21:39:32 raspi2 sudo[1793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:32 raspi2 sudo[1793]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:32 raspi2 sudo[1795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 21:39:32 raspi2 sudo[1795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:32 raspi2 volumio[1483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 21:39:32 raspi2 volumio[1483]: info: ___________ START PLUGINS ___________ Feb 23 21:39:32 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:32 raspi2 volumio[1483]: info: ControllerMpd::onStart: Initializing MPD Feb 23 21:39:32 raspi2 volumio[1483]: info: Creating MPD Configuration file Feb 23 21:39:32 raspi2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 21:39:32 raspi2 systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 21:39:32 raspi2 volumio[1483]: info: [1771904372852] CoreMusicLibrary::Adding element Media Servers Feb 23 21:39:32 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 21:39:32 raspi2 sudo[1808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 23 21:39:32 raspi2 sudo[1808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:32 raspi2 tailscaled[856]: dns: resolver: forward: recv: response code indicating server failure: 2 Feb 23 21:39:32 raspi2 volumio[1483]: info: UPNP Browser: Client initialized successfully Feb 23 21:39:32 raspi2 sudo[1812]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 21:39:32 raspi2 sudo[1812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 21:39:32 raspi2 sudo[1821]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 23 21:39:32 raspi2 sudo[1812]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:32 raspi2 sudo[1811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 21:39:32 raspi2 sudo[1811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:32 raspi2 sudo[1817]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 21:39:32 raspi2 sudo[1817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:33 raspi2 sudo[1811]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:33 raspi2 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 23 21:39:33 raspi2 sudo[1808]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:33 raspi2 systemd[1]: mpd.service: Deactivated successfully. Feb 23 21:39:33 raspi2 systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 21:39:33 raspi2 systemd[1]: mpd.socket: Deactivated successfully. Feb 23 21:39:33 raspi2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 21:39:33 raspi2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 21:39:33 raspi2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 21:39:33 raspi2 systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 21:39:33 raspi2 systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 23 21:39:33 raspi2 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 23 21:39:33 raspi2 sudo[1829]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 21:39:33 raspi2 sudo[1841]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 23 21:39:33 raspi2 sudo[1829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 21:39:33 raspi2 sudo[1829]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:33 raspi2 volumio[1483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:33 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:39:33.588-06:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 23 21:39:33 raspi2 volumio[1483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 21:39:33 raspi2 volumio[1483]: info: [1771904373609] CoreMusicLibrary::Adding element Last_100 Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 21:39:33 raspi2 volumio[1483]: info: [1771904373649] CoreMusicLibrary::Adding element Webradio Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 21:39:33 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 21:39:33 raspi2 volumio[1483]: info: Initializing BBC Radios Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:34 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:34 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 21:39:34 raspi2 volumio[1483]: info: [1771904374122] CoreMusicLibrary::Adding element Jellyfin Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 21:39:34 raspi2 volumio[1483]: Cannot find translation for source Jellyfin Feb 23 21:39:34 raspi2 volumio[1483]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.3.16","id":"681a86ee-8311-4198-a64b-b8c501747964","name":"Raspi2","serviceName":"Volumio","state":{"albumart":"http://100.93.223.101:8096/Items/9646e92e2d6eedb259ee57b4dc10afbd/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Chavela Vargas","mute":false,"status":"stop","track":"Fallaste corazón","volume":79},"type":"device"} Feb 23 21:39:34 raspi2 volumio[1483]: info: FusionDsp - CamillaDSP binary found. Feb 23 21:39:34 raspi2 volumio[1483]: info: Loading i18n strings for locale es Feb 23 21:39:34 raspi2 volumio[1483]: error: remotepi: Fetching language file: Error: i18n file complementing the system language not found. Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 23 21:39:34 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:34 raspi2 volumio[1483]: info: FusionDsp - mixtype--------------------- Hardware Feb 23 21:39:34 raspi2 volumio[1483]: info: Loading i18n strings for locale es Feb 23 21:39:34 raspi2 volumio[1483]: error: remotepi: Fetching language file: Error: i18n file complementing the system language not found. Feb 23 21:39:34 raspi2 volumio[1483]: info: Loading i18n strings for locale es Feb 23 21:39:34 raspi2 volumio[1483]: error: remotepi: Fetching language file: Error: i18n file complementing the system language not found. Feb 23 21:39:34 raspi2 volumio[1483]: info: Volumio Calling Home Feb 23 21:39:35 raspi2 volumio[1483]: info: Preparing to generate the ALSA configuration file Feb 23 21:39:35 raspi2 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Feb 23 21:39:35 raspi2 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 21:39:36 raspi2 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 23 21:39:36 raspi2 sudo[1776]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:37 raspi2 tailscaled[856]: dns: resolver: forward: recv: response code indicating server failure: 2 Feb 23 21:39:37 raspi2 volumio[1483]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 23 21:39:37 raspi2 mpd[1843]: 2026-02-23T21:39:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 21:39:37 raspi2 systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 21:39:37 raspi2 volumio[1483]: info: camilladsp service started and running in background, instance 1 Feb 23 21:39:37 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:37 raspi2 sudo[1817]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:37 raspi2 sudo[1795]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:37 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:37 raspi2 volumio[1483]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Feb 23 21:39:37 raspi2 volumio[1483]: info: FusionDsp loaded Feb 23 21:39:37 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:37 raspi2 volumio[1483]: info: FusionDsp - --[object Object] Feb 23 21:39:37 raspi2 volumio[1483]: error: FusionDsp - Socket connection not established Feb 23 21:39:37 raspi2 volumio[1483]: info: FusionDsp - Reporting Fusion DSP Enabled Feb 23 21:39:37 raspi2 volumio[1483]: info: Adding Signal Path Element [object Object] Feb 23 21:39:37 raspi2 volumio[1483]: info: Adding fusiondspeq DSP Signal Path Element Feb 23 21:39:37 raspi2 volumio[1483]: info: FusionDsp - ---- installed callbackRead (debounced 200ms) Feb 23 21:39:37 raspi2 volumio[1483]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 23 21:39:37 raspi2 volumio[1483]: info: Reading ALSA contributions from plugins. Feb 23 21:39:37 raspi2 sudo[1891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Feb 23 21:39:37 raspi2 sudo[1891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:37 raspi2 volumio[1483]: info: MPD Permissions set Feb 23 21:39:38 raspi2 volumio[1483]: info: MPD Permissions set Feb 23 21:39:38 raspi2 volumio[1483]: info: Upmpdcli Daemon Started Feb 23 21:39:38 raspi2 systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Feb 23 21:39:38 raspi2 volumio[1483]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Feb 23 21:39:38 raspi2 volumio[1483]: error: FusionDsp - Reload WebSocket error: [object Object] Feb 23 21:39:38 raspi2 volumio[1483]: info: Volumio called home Feb 23 21:39:38 raspi2 volumio[1483]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Feb 23 21:39:38 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:38 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:38 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:38 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:39:38.345-06:00 level=INFO msg="system info for 92213a62daaafd319723faa2ef63bdc0" deviceName=Raspi2 deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 23 21:39:38 raspi2 volumio[1483]: error: MPD error: The expression evaluated to a falsy value: Feb 23 21:39:38 raspi2 volumio[1483]: assert.ok(self.idling) Feb 23 21:39:38 raspi2 volumio[1483]: error: The expression evaluated to a falsy value: Feb 23 21:39:38 raspi2 volumio[1483]: assert.ok(self.idling) Feb 23 21:39:38 raspi2 volumio[1483]: info: MPD running with PID1843 Feb 23 21:39:38 raspi2 volumio[1483]: ,establishing connection Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:38 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:38 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:38 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:38 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:38 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:38 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:38 raspi2 volumio[1483]: error: updateQueue error: null Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:39 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:39 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 23 21:39:39 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:39:39.230-06:00 level=INFO msg="enabling local network discovery" Feb 23 21:39:39 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:39:39.266-06:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 23 21:39:39 raspi2 sudo[1911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod o+rx /sys/kernel/debug Feb 23 21:39:39 raspi2 sudo[1911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:39 raspi2 sudo[1911]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:39 raspi2 volumio[1483]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 23 21:39:39 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:39 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:39 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:39 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:39 raspi2 volumio[1483]: info: [jellyfin-poller] Polled http://100.93.223.101:8096: online Feb 23 21:39:39 raspi2 volumio[1483]: error: updateQueue error: null Feb 23 21:39:39 raspi2 volumio[1483]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 23 21:39:39 raspi2 volumio[1483]: info: Starting Shairport Sync Feb 23 21:39:39 raspi2 volumio[1483]: info: Starting Shairport Sync Feb 23 21:39:39 raspi2 volumio[1483]: info: Starting Shairport Sync Feb 23 21:39:39 raspi2 volumio-remote-updater[860]: Test mode disabled Feb 23 21:39:39 raspi2 volumio-remote-updater[860]: Alpha mode disabled Feb 23 21:39:39 raspi2 volumio-remote-updater[860]: Alpha legacy test mode disabled Feb 23 21:39:39 raspi2 sudo[1931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 21:39:39 raspi2 sudo[1931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:39 raspi2 sudo[1928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 21:39:39 raspi2 sudo[1928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:39 raspi2 volumio[1483]: verbose: New Socket.io Connection to 192.168.3.16:3000 from 192.168.3.6 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Feb 23 21:39:39 raspi2 systemd[1]: volumio-remote-updater.service: Main process exited, code=killed, status=6/ABRT Feb 23 21:39:39 raspi2 volumio-remote-updater[860]: curl_easy_perform() failed: Couldn't resolve host name Feb 23 21:39:39 raspi2 volumio-remote-updater[860]: terminate called after throwing an instance of 'std::invalid_argument' Feb 23 21:39:39 raspi2 volumio-remote-updater[860]: what(): parse error - unexpected end of input Feb 23 21:39:39 raspi2 systemd[1]: volumio-remote-updater.service: Failed with result 'signal'. Feb 23 21:39:39 raspi2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 21:39:39 raspi2 systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 21:39:39 raspi2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 21:39:39 raspi2 systemd[1]: shairport-sync.service: Consumed 1.734s CPU time. Feb 23 21:39:39 raspi2 sudo[1935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 21:39:39 raspi2 sudo[1935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:39 raspi2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 21:39:39 raspi2 systemd[1]: volumio-remote-updater.service: Scheduled restart job, restart counter is at 1. Feb 23 21:39:39 raspi2 sudo[1931]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:39 raspi2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 21:39:39 raspi2 systemd[1]: Stopped volumio-remote-updater.service - Volumio Remote OTA Updater. Feb 23 21:39:40 raspi2 systemd[1]: Started volumio-remote-updater.service - Volumio Remote OTA Updater. Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 23 21:39:40 raspi2 systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 21:39:40 raspi2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 21:39:40 raspi2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 21:39:40 raspi2 volumio-remote-updater[1940]: Volumio OTA Client: 1.7.0 Feb 23 21:39:40 raspi2 volumio-remote-updater[1940]: Error: No active session Feb 23 21:39:40 raspi2 volumio-remote-updater[1940]: [2026-02-23 21:39:40] [connect] Successful connection Feb 23 21:39:40 raspi2 sudo[1935]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:40 raspi2 sudo[1928]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:40 raspi2 volumio[1483]: verbose: New Socket.io Connection to 192.168.3.16:3000 from 192.168.3.6 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Feb 23 21:39:40 raspi2 volumio[1483]: info: Shairport-Sync Started Feb 23 21:39:40 raspi2 volumio[1483]: Error adding Membership: Error: addMembership EINVAL Feb 23 21:39:40 raspi2 volumio[1483]: info: Asound.conf file unchanged, so no further update is needed Feb 23 21:39:40 raspi2 volumio[1483]: info: Output device has changed, restarting MPD Feb 23 21:39:40 raspi2 volumio[1483]: info: Output device has changed, restarting Shairport Sync Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:40 raspi2 sudo[1960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 21:39:40 raspi2 sudo[1962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 21:39:40 raspi2 sudo[1962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:40 raspi2 sudo[1960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:40 raspi2 volumio[1483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 21:39:40 raspi2 sudo[1960]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 23 21:39:40 raspi2 volumio[1483]: info: Shairport-Sync Started Feb 23 21:39:40 raspi2 volumio[1483]: info: Shairport-Sync Started Feb 23 21:39:40 raspi2 systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:40 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:40 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:40 raspi2 volumio[1483]: info: MPD Permissions set Feb 23 21:39:40 raspi2 systemd[1]: mpd.service: Deactivated successfully. Feb 23 21:39:40 raspi2 systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 21:39:40 raspi2 systemd[1]: mpd.service: Consumed 3.038s CPU time. Feb 23 21:39:40 raspi2 systemd[1]: mpd.socket: Deactivated successfully. Feb 23 21:39:40 raspi2 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 21:39:40 raspi2 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 21:39:40 raspi2 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 21:39:40 raspi2 systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 21:39:41 raspi2 sudo[1970]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 21:39:41 raspi2 sudo[1970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 21:39:41 raspi2 sudo[1970]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:41 raspi2 volumio[1483]: info: Completed starting Core Plugins Feb 23 21:39:41 raspi2 volumio[1483]: info: ------------------------------------------- Feb 23 21:39:41 raspi2 volumio[1483]: info: ----- MyVolumio plugins startup ---- Feb 23 21:39:41 raspi2 volumio[1483]: info: ------------------------------------------- Feb 23 21:39:41 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 23 21:39:41 raspi2 volumio[1483]: error: Upnp client error: Error: This socket has been ended by the other party Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:39:41 raspi2 volumio[1483]: verbose: New Socket.io Connection to 192.168.3.16:3000 from 192.168.3.6 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 4 Feb 23 21:39:41 raspi2 volumio-remote-updater[1940]: [2026-02-23 21:39:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771904380 101 Feb 23 21:39:41 raspi2 volumio[1483]: 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: 5 Feb 23 21:39:42 raspi2 volumio[1483]: verbose: New Socket.io Connection to 192.168.3.16:3000 from 192.168.3.6 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Feb 23 21:39:42 raspi2 volumio[1483]: info: Starting Shairport Sync Feb 23 21:39:42 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 23 21:39:42 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 23 21:39:42 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:42 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:42 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:42 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:42 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:42 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:42 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:42 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:42 raspi2 sudo[1994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 21:39:42 raspi2 sudo[1994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:42 raspi2 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 21:39:42 raspi2 systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 21:39:42 raspi2 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 21:39:42 raspi2 systemd[1]: shairport-sync.service: Consumed 1.225s CPU time. Feb 23 21:39:42 raspi2 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 21:39:42 raspi2 sudo[1994]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:42 raspi2 volumio[1483]: info: Shairport-Sync Started Feb 23 21:39:42 raspi2 mpd[1973]: 2026-02-23T21:39:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 21:39:42 raspi2 systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 21:39:42 raspi2 sudo[1962]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:42 raspi2 volumio[1483]: error: updateQueue error: null Feb 23 21:39:42 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:43 raspi2 systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 23 21:39:43 raspi2 sudo[1891]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:43 raspi2 volumio[1483]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:47 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:47 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 23 21:39:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Feb 23 21:39:47 raspi2 sudo[2026]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Feb 23 21:39:47 raspi2 sudo[2026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:47 raspi2 sudo[2022]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Feb 23 21:39:47 raspi2 sudo[2022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:48 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:48 raspi2 sudo[2022]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:48 raspi2 sudo[2026]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:48 raspi2 sudo[2038]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Feb 23 21:39:48 raspi2 sudo[2043]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 21:39:48 raspi2 sudo[2043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:48 raspi2 sudo[2038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:48 raspi2 sudo[2038]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:48 raspi2 sudo[2043]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:48 raspi2 sudo[2032]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Feb 23 21:39:48 raspi2 sudo[2032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:48 raspi2 sudo[2045]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 21:39:48 raspi2 sudo[2032]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:48 raspi2 sudo[2045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:39:48 raspi2 sudo[2045]: pam_unix(sudo:session): session closed for user root Feb 23 21:39:48 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 23 21:39:48 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 23 21:39:48 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:39:48 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:39:48 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:39:48 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:39:48 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:39:48 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:39:48 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:39:48.334-06:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.3.6:49058 Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 21:39:49 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 21:39:50 raspi2 volumio[1483]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 21:39:50 raspi2 volumio[1483]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 21:39:50 raspi2 volumio[1483]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 21:39:50 raspi2 volumio[1483]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 21:39:50 raspi2 volumio[1483]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 21:39:50 raspi2 volumio[1483]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 21:39:50 raspi2 volumio[1483]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 21:39:50 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 21:39:53 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:39:56 raspi2 volumio[1483]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 21:39:56 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 21:39:56 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:56 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:39:56 raspi2 volumio[1483]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 21:39:57 raspi2 volumio[1483]: info: MyVolumio login type: Token Feb 23 21:39:57 raspi2 volumio[1483]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 21:39:57 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 21:39:58 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:39:58.064-06:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.3.6:39354 Feb 23 21:39:58 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:01 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:01.372-06:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.3.6:39354 Feb 23 21:40:01 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:01.379-06:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.3.6:39370 Feb 23 21:40:02 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 21:40:02 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 21:40:02 raspi2 volumio[1483]: info: Streaming services startup Feb 23 21:40:02 raspi2 volumio[1483]: info: Starting Streaming Daemon Feb 23 21:40:02 raspi2 sudo[2081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 21:40:02 raspi2 sudo[2081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:40:02 raspi2 volumio[1483]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 21:40:03 raspi2 sudo[2081]: pam_unix(sudo:session): session closed for user root Feb 23 21:40:03 raspi2 volumio[1483]: info: Bluetoothremote--- Checking for trusted devices to reconnect... Feb 23 21:40:03 raspi2 volumio[1483]: info: Bluetoothremote--- Device list cleared and placeholder written. Feb 23 21:40:03 raspi2 volumio[1483]: error: Cannot start Volumio Streaming Daemon Feb 23 21:40:03 raspi2 volumio[1483]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 21:40:03 raspi2 volumio[1483]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 21:40:03 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:03 raspi2 bluetoothd[845]: Path / reserved for Adv Monitor app :1.21 Feb 23 21:40:03 raspi2 bluetoothd[845]: Adv Monitor app :1.21 disconnected from D-Bus Feb 23 21:40:03 raspi2 volumio[1483]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 21:40:03 raspi2 volumio[1483]: error: MyVolumio Custom Token format not valid, refreshing it Feb 23 21:40:04 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 21:40:04 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:04 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 23 21:40:04 raspi2 volumio[1483]: info: Bluetoothremote--- Device found: Press scan to detect BT device - xx Feb 23 21:40:04 raspi2 bluetoothd[845]: Path / reserved for Adv Monitor app :1.22 Feb 23 21:40:04 raspi2 bluetoothd[845]: Adv Monitor app :1.22 disconnected from D-Bus Feb 23 21:40:04 raspi2 volumio-remote-updater[1940]: Test mode disabled Feb 23 21:40:04 raspi2 volumio-remote-updater[1940]: Alpha mode disabled Feb 23 21:40:04 raspi2 volumio-remote-updater[1940]: Alpha legacy test mode disabled Feb 23 21:40:04 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 23 21:40:05 raspi2 volumio[1483]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.348-06:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.349-06:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.349-06:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.564-06:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.3.6:39354 Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.565-06:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.3.6:49058 @ 0x2000d20" latency=14.738546831s timeout=10s Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.565-06:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.566-06:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.3.6:49058 Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.566-06:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.3.6:49058 Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.566-06:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.3.6:49058 @ 0x2000d20" latency=14.738773402s platform=PLATFORM_ANDROID version=5.260120.0 Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.567-06:00 level=ERROR msg="failed to send event" component=server dst="192.168.3.6:49058 @ 0x2000d20" event=SERVER_EVENT_TYPE_DEVICE_CAPABILITIES_CHANGED error="no addresses to write to" Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 23 21:40:05 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:05 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:05 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.591-06:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" name=Raspi2 Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.591-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_DEVICE_NAME_CHANGED error="no addresses to write to" Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.592-06:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" language=es Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.592-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_DEVICE_LANGUAGE_CHANGED error="no addresses to write to" Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.613-06:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" timezone=America/Mexico_City Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.613-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_DEVICE_TIMEZONE_CHANGED error="no addresses to write to" Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.619-06:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" available=true connected=true macAddress=dc:a6:32:b3:05:2a ip4Address=192.168.3.16/24 ip6Address= Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.619-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_ETHERNET_INFO_CHANGED error="no addresses to write to" Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.620-06:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.620-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED error="no addresses to write to" Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.620-06:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" setupComplete=true Feb 23 21:40:05 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:05.621-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_DEVICE_SETUP_STATUS_CHANGED error="no addresses to write to" Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:05 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 23 21:40:05 raspi2 volumio[1483]: amixer -c 0 info | grep "bcm2835 ALSA" Feb 23 21:40:05 raspi2 volumio[1483]: amixer -c 1 info | grep "bcm2835 Headphones" Feb 23 21:40:06 raspi2 volumio[1483]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Feb 23 21:40:06 raspi2 volumio[1483]: amixer -c 2 info | grep "vc4-hdmi-0" Feb 23 21:40:06 raspi2 volumio[1483]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Feb 23 21:40:06 raspi2 volumio[1483]: amixer -c 3 info | grep "vc4-hdmi-1" Feb 23 21:40:06 raspi2 volumio[1483]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Feb 23 21:40:06 raspi2 volumio[1483]: amixer -c 4 info | grep "BossDAC" Feb 23 21:40:06 raspi2 volumio[1483]: Card sysdefault:4 'BossDAC'/'BossDAC' Feb 23 21:40:06 raspi2 volumio[1483]: info: MyVolumio login type: Token Feb 23 21:40:06 raspi2 volumio[1483]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Feb 23 21:40:06 raspi2 volumio[1483]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 23 21:40:06 raspi2 volumio[1483]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 23 21:40:06 raspi2 volumio[1483]: amixer -c 4 info | grep "Innomaker Dac" Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.574-06:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" selectedOutputId=4 Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.575-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_AUDIO_OUTPUTS_CHANGED error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:06 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:06 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:06 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:06 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:06 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:06 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.598-06:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" currentVersion=4.096 latestVersion=4.096 Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.598-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_SOFTWARE_INFO_CHANGED error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.598-06:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.3.6:49058 @ 0x2000d20" status=UPDATE_STATUS_NONE progress=0 Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.598-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_SOFTWARE_UPDATE_PROGRESS error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.598-06:00 level=INFO msg="emitting user changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" userId= Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.598-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_USER_CHANGED error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.598-06:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" providers=3 Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.599-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_MUSIC_PROVIDERS_CHANGED error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.634-06:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" plugins=0 Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.634-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_PLUGINS_CHANGED error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:06 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.650-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" state=STATUS_STOPPED positionMs=0 volume=79 Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.651-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.651-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:49058 @ 0x2000d20" id="jellyfin/admin@6bc0268ab0324cb1b2d4940ee8e33124/song@songId=9646e92e2d6eedb259ee57b4dc10afbd" title="Fallaste corazón" Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.651-06:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2000d20" event=SERVER_EVENT_TYPE_PLAYER_METADATA_CHANGED error="no addresses to write to" Feb 23 21:40:06 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:06.651-06:00 level=ERROR msg="failed to send response" component=server dst=" @ 0x2000d20" id=1059657860 status=STATUS_OK error="no addresses to write to" Feb 23 21:40:07 raspi2 volumio[1483]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 23 21:40:07 raspi2 volumio[1483]: info: MyVolumio token set successfully Feb 23 21:40:07 raspi2 volumio[1483]: info: MYVOLUMIO: Adding device Feb 23 21:40:07 raspi2 volumio[1483]: info: MYVOLUMIO: Evaluating Server Feb 23 21:40:07 raspi2 tailscaled[856]: dns: resolver: forward: recv: response code indicating server failure: 2 Feb 23 21:40:08 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:08 raspi2 volumio[1483]: info: MyVolumio status changed Feb 23 21:40:08 raspi2 volumio[1483]: info: Streaming services startup Feb 23 21:40:08 raspi2 upmpdcli[2146]: writing RSA key Feb 23 21:40:08 raspi2 volumio[1483]: info: Starting Streaming Daemon Feb 23 21:40:08 raspi2 volumio[1483]: info: Removing browser output: myVolumio user plan is not superstar Feb 23 21:40:08 raspi2 volumio[1483]: info: Removing audio output: Feb 23 21:40:08 raspi2 volumio[1483]: info: Stoppping Tunnel 1 Feb 23 21:40:08 raspi2 sudo[2150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 21:40:08 raspi2 sudo[2150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:40:08 raspi2 sudo[2152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 23 21:40:08 raspi2 sudo[2152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:40:08 raspi2 sudo[2150]: pam_unix(sudo:session): session closed for user root Feb 23 21:40:08 raspi2 volumio[1483]: info: Setting Geolocation for MyVolumio to us1 Feb 23 21:40:08 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:08 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:08 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:08 raspi2 volumio[1483]: error: Cannot start Volumio Streaming Daemon Feb 23 21:40:08 raspi2 volumio[1483]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 21:40:08 raspi2 volumio[1483]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 sudo[2152]: pam_unix(sudo:session): session closed for user root Feb 23 21:40:08 raspi2 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 23 21:40:08 raspi2 volumio[1483]: info: Remote SSH Stopped Feb 23 21:40:09 raspi2 volumio[1483]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 23 21:40:09 raspi2 volumio[1483]: info: Updating MyVolumio device info Feb 23 21:40:09 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:09 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:09 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:10 raspi2 volumio[1483]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 23 21:40:11 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 21:40:11 raspi2 volumio[1483]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 23 21:40:12 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:12 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:13 raspi2 volumio[1483]: info: MYVOLUMIO: Adding device Feb 23 21:40:13 raspi2 volumio[1483]: info: MYVOLUMIO: Evaluating Server Feb 23 21:40:13 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:13 raspi2 volumio[1483]: info: Setting Geolocation for MyVolumio to us1 Feb 23 21:40:13 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:13 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:13 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:14 raspi2 volumio[1483]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 23 21:40:14 raspi2 volumio[1483]: info: Updating MyVolumio device info Feb 23 21:40:14 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:14 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:14 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:15 raspi2 volumio[1483]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetBrowseSources Feb 23 21:40:16 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 21:40:18 raspi2 tailscaled[856]: open-conn-track: timeout opening (TCP 100.85.253.93:33934 => 100.118.77.44:53) to node [J0zmE]; online=no, lastseen=3h53m15s, lastRecv=never Feb 23 21:40:18 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:22 raspi2 volumio[1483]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 23 21:40:22 raspi2 volumio[1483]: info: Completed starting MyVolumio Plugin Feb 23 21:40:22 raspi2 volumio[1483]: [Metrics] CommandRouter: 77s 68.60ms Feb 23 21:40:22 raspi2 volumio[1483]: info: CoreCommandRouter::volumiosetStartupVolume Feb 23 21:40:22 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 21:40:22 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:22 raspi2 volumio[1483]: info: CoreCommandRouter::Close All Modals sent Feb 23 21:40:23 raspi2 volumio[1483]: info: CoreCommandRouter::Close All Modals sent Feb 23 21:40:23 raspi2 volumio[1483]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 23 21:40:23 raspi2 volumio[1483]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 23 21:40:23 raspi2 volumio[1483]: info: camilladsp stopping service pid 1884... Feb 23 21:40:23 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:23 raspi2 volumio[1483]: grep: /proc/1884/cmdline: binary file matches Feb 23 21:40:23 raspi2 volumio[1483]: grep: /proc/1884/cmdline: binary file matches Feb 23 21:40:23 raspi2 volumio[1483]: grep: /proc/1884/cmdline: binary file matches Feb 23 21:40:23 raspi2 volumio[1483]: grep: /proc/1884/cmdline: binary file matches Feb 23 21:40:23 raspi2 volumio[1483]: info: camilladsp service terminated, instance 1 Feb 23 21:40:23 raspi2 volumio[1483]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 23 21:40:23 raspi2 volumio[1483]: info: camilladsp service started and running in background, instance 1 Feb 23 21:40:23 raspi2 volumio[1483]: info: camilladsp respawn in 100 ms (attempt 1/10) Feb 23 21:40:24 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 23 21:40:24 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 23 21:40:24 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 23 21:40:28 raspi2 volumio[1483]: info: camilladsp respawn in 200 ms (attempt 2/10) Feb 23 21:40:28 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:30 raspi2 volumio[1483]: info: BOOT COMPLETED Feb 23 21:40:33 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:38 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.196-06:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.3.6:39370 @ 0x211e2a0" latency=36.816102ms timeout=10s Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.196-06:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.196-06:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.3.6:39370 @ 0x211e2a0" latency=38.801806ms platform=PLATFORM_ANDROID version=5.260120.0 Feb 23 21:40:40 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:40 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:40 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.215-06:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" name=Raspi2 Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.216-06:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" language=es Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.219-06:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" timezone=America/Mexico_City Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.220-06:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" available=true connected=true macAddress=dc:a6:32:b3:05:2a ip4Address=192.168.3.16/24 ip6Address= Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.221-06:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.222-06:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" setupComplete=true Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 21:40:40 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 23 21:40:40 raspi2 volumio[1483]: amixer -c 0 info | grep "bcm2835 ALSA" Feb 23 21:40:40 raspi2 volumio[1483]: amixer -c 1 info | grep "bcm2835 Headphones" Feb 23 21:40:40 raspi2 volumio[1483]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Feb 23 21:40:40 raspi2 volumio[1483]: amixer -c 2 info | grep "vc4-hdmi-0" Feb 23 21:40:40 raspi2 volumio[1483]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Feb 23 21:40:40 raspi2 volumio[1483]: amixer -c 3 info | grep "vc4-hdmi-1" Feb 23 21:40:40 raspi2 volumio[1483]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Feb 23 21:40:40 raspi2 volumio[1483]: amixer -c 4 info | grep "BossDAC" Feb 23 21:40:40 raspi2 volumio[1483]: Card sysdefault:4 'BossDAC'/'BossDAC' Feb 23 21:40:40 raspi2 volumio[1483]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Feb 23 21:40:40 raspi2 volumio[1483]: /bin/sh: 1: /usr/local/bin/alsacap: not found Feb 23 21:40:40 raspi2 volumio[1483]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Feb 23 21:40:40 raspi2 volumio[1483]: amixer -c 4 info | grep "Innomaker Dac" Feb 23 21:40:40 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:40.996-06:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" selectedOutputId=4 Feb 23 21:40:41 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:41 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:41 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:41 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:41 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:41.037-06:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" currentVersion=4.096 latestVersion=4.096 Feb 23 21:40:41 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:41.037-06:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" status=UPDATE_STATUS_NONE progress=0 Feb 23 21:40:41 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:41.038-06:00 level=INFO msg="emitting user changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" userId= Feb 23 21:40:41 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:41.038-06:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" providers=3 Feb 23 21:40:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:41 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 21:40:42 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:42.354-06:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" plugins=60 Feb 23 21:40:42 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:42 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:42 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:42.377-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" state=STATUS_STOPPED positionMs=0 volume=79 Feb 23 21:40:42 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:42.377-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.3.6:39370 @ 0x211e2a0" id="jellyfin/admin@6bc0268ab0324cb1b2d4940ee8e33124/song@songId=9646e92e2d6eedb259ee57b4dc10afbd" title="Fallaste corazón" Feb 23 21:40:42 raspi2 volumio5-onboarding[1825]: time=2026-02-23T21:40:42.395-06:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.3.6:39370 @ 0x211e2a0" latency=25.757869ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Feb 23 21:40:44 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:44 raspi2 sudo[2301]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 21:40:44 raspi2 sudo[2302]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 21:40:44 raspi2 sudo[2301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:40:44 raspi2 sudo[2302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:40:44 raspi2 sudo[2302]: pam_unix(sudo:session): session closed for user root Feb 23 21:40:44 raspi2 sudo[2301]: pam_unix(sudo:session): session closed for user root Feb 23 21:40:44 raspi2 volumio[1483]: verbose: New Socket.io Connection to 192.168.3.16 from 192.168.3.6 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetVisibleSources Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:45 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 23 21:40:45 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:45 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:45 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:45 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:45 raspi2 volumio[1483]: info: Listing playlists Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 21:40:45 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 23 21:40:45 raspi2 sudo[2309]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 21:40:45 raspi2 sudo[2309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:40:45 raspi2 sudo[2309]: pam_unix(sudo:session): session closed for user root Feb 23 21:40:45 raspi2 sudo[2311]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 21:40:45 raspi2 sudo[2311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:40:45 raspi2 sudo[2311]: pam_unix(sudo:session): session closed for user root Feb 23 21:40:45 raspi2 volumio[1483]: verbose: New Socket.io Connection to 192.168.3.16 from 192.168.3.6 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetVisibleSources Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:46 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 23 21:40:46 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:46 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:46 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:46 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:46 raspi2 volumio[1483]: info: Listing playlists Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 23 21:40:46 raspi2 volumio[1483]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 21:40:47 raspi2 tailscaled[856]: Received error: PollNetMap: unexpected EOF Feb 23 21:40:47 raspi2 tailscaled[856]: control: controlhttp: forcing port 443 dial due to recent noise dial Feb 23 21:40:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:47 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:47 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:47 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:47 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 23 21:40:47 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 21:40:48 raspi2 tailscaled[856]: control: netmap: got new dial plan from control Feb 23 21:40:49 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:50 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 21:40:50 raspi2 volumio[1483]: info: Received Get System Info Feb 23 21:40:50 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 21:40:50 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 21:40:50 raspi2 volumio[1483]: info: Discovery: Getting this device information Feb 23 21:40:50 raspi2 volumio[1483]: info: CoreCommandRouter::volumioGetState Feb 23 21:40:50 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:50 raspi2 volumio[1483]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 21:40:53 raspi2 volumio[1483]: info: CoreCommandRouter::volumioPlay Feb 23 21:40:53 raspi2 volumio[1483]: info: CoreStateMachine::play index undefined Feb 23 21:40:53 raspi2 volumio[1483]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 23 21:40:53 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:53 raspi2 volumio[1483]: info: CoreStateMachine::startPlaybackTimer Feb 23 21:40:53 raspi2 volumio[1483]: info: CorePlayQueue::getTrack 0 Feb 23 21:40:53 raspi2 volumio[1483]: info: [jellyfin-play] clearAddPlayTrack: jellyfin/admin@6bc0268ab0324cb1b2d4940ee8e33124/song@songId=9646e92e2d6eedb259ee57b4dc10afbd Feb 23 21:40:53 raspi2 volumio[1483]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 21:40:53 raspi2 volumio[1483]: Error: Server unavailable Feb 23 21:40:53 raspi2 volumio[1483]: at PlayController.getSongFromTrack (/data/plugins/music_service/jellyfin/dist/lib/controller/play/PlayController.js:166:19) Feb 23 21:40:53 raspi2 volumio[1483]: at PlayController.clearAddPlayTrack (/data/plugins/music_service/jellyfin/dist/lib/controller/play/PlayController.js:77:49) Feb 23 21:40:53 raspi2 volumio[1483]: at ControllerJellyfin.clearAddPlayTrack (/data/plugins/music_service/jellyfin/dist/index.js:405:87) Feb 23 21:40:53 raspi2 volumio[1483]: at Promise._successFn (/volumio/app/statemachine.js:1028:24) Feb 23 21:40:53 raspi2 volumio[1483]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 23 21:40:53 raspi2 volumio[1483]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Feb 23 21:40:53 raspi2 volumio[1483]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 21:40:54 raspi2 tailscaled[856]: magicsock: derp-9 does not know about peer [J0zmE], removing route Feb 23 21:40:56 raspi2 sudo[2346]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 21:39' Feb 23 21:40:56 raspi2 sudo[2346]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"