Aug 29 22:11:04 volumio-tau ntpd[770]: CLOCK: time stepped by 5527265.611587 Aug 29 22:11:04 volumio-tau ntpd[770]: CLOCK: time changed from 2026-06-26 to 2026-08-29 Aug 29 22:11:04 volumio-tau ntpd[770]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 29 22:11:05 volumio-tau volumio[1039]: info: MYVOLUMIO Environment detected Aug 29 22:11:05 volumio-tau volumio[1039]: info: Plugin folders cleanup Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning into folder /volumio/app/plugins/ Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning category audio_interface Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning category miscellanea Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning category music_service Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning category plugins.json Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning category system_controller Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning category user_interface Aug 29 22:11:05 volumio-tau volumio[1039]: info: Scanning into folder /data/plugins/ Aug 29 22:11:05 volumio-tau volumio[1039]: info: Plugin folders cleanup completed Aug 29 22:11:05 volumio-tau volumio[1039]: info: ------------------------------------------- Aug 29 22:11:05 volumio-tau volumio[1039]: info: ----- Core plugins startup ---- Aug 29 22:11:05 volumio-tau volumio[1039]: info: ------------------------------------------- Aug 29 22:11:05 volumio-tau volumio[1039]: info: Loading plugins from folder /volumio/app/plugins/ Aug 29 22:11:05 volumio-tau volumio[1039]: info: Adding plugin upnp to MyMusic Plugins Aug 29 22:11:05 volumio-tau volumio[1039]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 29 22:11:05 volumio-tau volumio[1039]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 29 22:11:05 volumio-tau volumio[1039]: info: Loading plugins from folder /data/plugins/ Aug 29 22:11:05 volumio-tau volumio[1039]: info: Loading plugin "system"... Aug 29 22:11:05 volumio-tau volumio[1039]: info: Loading plugin "appearance"... Aug 29 22:11:07 volumio-tau volumio[1039]: info: Loading plugin "network"... Aug 29 22:11:08 volumio-tau volumio[1039]: info: Refreshing Cached IP Addresses Aug 29 22:11:08 volumio-tau volumio[1039]: info: Loading plugin "services"... Aug 29 22:11:08 volumio-tau sudo[1209]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 22:11:08 volumio-tau sudo[1209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:08 volumio-tau sudo[1209]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:08 volumio-tau sudo[1208]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 22:11:08 volumio-tau volumio[1039]: info: Loading plugin "volumio5onboarding"... Aug 29 22:11:08 volumio-tau sudo[1220]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 29 22:11:08 volumio-tau sudo[1220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:08 volumio-tau sudo[1208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:08 volumio-tau sudo[1208]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:08 volumio-tau volumio[1039]: info: Loading plugin "alsa_controller"... Aug 29 22:11:08 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 22:11:08 volumio-tau volumio[1039]: info: Loading plugin "wizard"... Aug 29 22:11:08 volumio-tau volumio[1039]: info: Loading plugin "networkfs"... Aug 29 22:11:08 volumio-tau volumio[1039]: info: Starting Udev Watcher for removable devices Aug 29 22:11:08 volumio-tau volumio[1039]: info: Ignoring mount for partition: boot Aug 29 22:11:08 volumio-tau volumio[1039]: info: Ignoring mount for partition: volumio Aug 29 22:11:08 volumio-tau volumio[1039]: info: Ignoring mount for partition: volumio_data Aug 29 22:11:08 volumio-tau volumio[1039]: info: Mounting Device USB_MEMORY Aug 29 22:11:08 volumio-tau systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 29 22:11:08 volumio-tau sudo[1248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/USB_MEMORY -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Aug 29 22:11:08 volumio-tau sudo[1248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:08 volumio-tau systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 29 22:11:08 volumio-tau systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 29 22:11:08 volumio-tau systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 29 22:11:08 volumio-tau systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 22:11:08 volumio-tau systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 22:11:09 volumio-tau systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 29 22:11:09 volumio-tau systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 29 22:11:09 volumio-tau systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 29 22:11:09 volumio-tau kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Aug 29 22:11:09 volumio-tau sudo[1220]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:09 volumio-tau sudo[1248]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:09 volumio-tau kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Aug 29 22:11:09 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 22:11:09 volumio-tau volumio[1039]: info: Loading plugin "volumio_command_line_client"... Aug 29 22:11:09 volumio-tau volumio[1039]: info: Loading plugin "upnp"... Aug 29 22:11:09 volumio-tau systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 29 22:11:09 volumio-tau systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 29 22:11:09 volumio-tau volumio[1039]: info: [1788009069359] Starting Upmpd Daemon Aug 29 22:11:09 volumio-tau upmpdcli[1254]: Could not open config: /tmp/upmpdcli.conf Aug 29 22:11:09 volumio-tau systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 22:11:09 volumio-tau systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 22:11:09 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 22:11:09 volumio-tau volumio[1039]: info: Loading plugin "my_music"... Aug 29 22:11:09 volumio-tau volumio[1039]: info: Loading plugin "mpd"... Aug 29 22:11:10 volumio-tau volumio[1039]: info: Loading plugin "upnp_browser"... Aug 29 22:11:10 volumio-tau volumio-remote-updater[606]: [2026-08-29 22:11:10] [connect] Successful connection Aug 29 22:11:11 volumio-tau systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 29 22:11:13 volumio-tau volumio[1039]: info: Starting UPNP Browser Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "alarm-clock"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "airplay_emulation"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: Starting Shairport Sync Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "last_100"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "webradio"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "i2s_dacs"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: I2S DAC not set, start Auto-detection Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "volumiodiscovery"... Aug 29 22:11:13 volumio-tau volumio[1039]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 22:11:13 volumio-tau volumio[1039]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 22:11:13 volumio-tau volumio[1039]: *** WARNING *** For more information see Aug 29 22:11:13 volumio-tau volumio[1039]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 22:11:13 volumio-tau volumio[1039]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 22:11:13 volumio-tau volumio[1039]: *** WARNING *** For more information see Aug 29 22:11:13 volumio-tau node[1039]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 22:11:13 volumio-tau node[1039]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 22:11:13 volumio-tau node[1039]: *** WARNING *** For more information see Aug 29 22:11:13 volumio-tau node[1039]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 22:11:13 volumio-tau node[1039]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 22:11:13 volumio-tau node[1039]: *** WARNING *** For more information see Aug 29 22:11:13 volumio-tau volumio[1039]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 29 22:11:13 volumio-tau volumio[1039]: info: Discovery: Started advertising with name: Volumio-tau Aug 29 22:11:13 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "outputs"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "albumart"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: Plugin example_plugin is not enabled Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "inputs"... Aug 29 22:11:13 volumio-tau volumio[1039]: info: Loading plugin "updater_comm"... Aug 29 22:11:14 volumio-tau volumio[1039]: info: Plugin mpdemulation is not enabled Aug 29 22:11:14 volumio-tau volumio[1039]: info: Loading plugin "rest_api"... Aug 29 22:11:14 volumio-tau volumio[1039]: info: Loading plugin "websocket"... Aug 29 22:11:14 volumio-tau volumio[1039]: info: Starting Socket.io Server version 1.7.4 Aug 29 22:11:14 volumio-tau volumio[1039]: info: Loading i18n strings for locale ja Aug 29 22:11:14 volumio-tau volumio[1039]: Updating browse sources language Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::initPlayerControls Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 22:11:14 volumio-tau volumio[1039]: Express server listening on port 3000 Aug 29 22:11:14 volumio-tau volumio[1039]: [Metrics] WebUI: 13s 437.13ms Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreStateMachine::resetVolumioState Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreStateMachine::getcurrentVolume Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 22:11:14 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:15 volumio-tau volumio[1039]: info: Volumio Network Manager: Network status updated: 2 Aug 29 22:11:15 volumio-tau volumio-remote-updater[606]: [2026-08-29 22:11:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788009070 101 Aug 29 22:11:15 volumio-tau volumio[1039]: 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 Aug 29 22:11:15 volumio-tau volumio[1039]: info: Reloading queue from file Aug 29 22:11:15 volumio-tau volumio[1039]: info: VolumeController:: Volume=90 Mute =false Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreStateMachine::pushState Aug 29 22:11:15 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioPushState Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreStateMachine::updateTrackBlock Aug 29 22:11:15 volumio-tau volumio[1039]: info: CorePlayQueue::getTrackBlock Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreStateMachine::setRepeat null single undefined Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreStateMachine::pushState Aug 29 22:11:15 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioPushState Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreStateMachine::setRandom null Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreStateMachine::pushState Aug 29 22:11:15 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:15 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioPushState Aug 29 22:11:15 volumio-tau volumio[1039]: info: Setting Device type: Raspberry PI Aug 29 22:11:15 volumio-tau volumio[1039]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 29 22:11:15 volumio-tau volumio[1039]: info: USB Boot Capable - System SBC Revision found in cpuinfo: 902120 Aug 29 22:11:15 volumio-tau volumio[1039]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 29 22:11:16 volumio-tau volumio[1039]: info: Discovery: adding de8c6e8d-814c-44a8-8600-652132215e81 Aug 29 22:11:16 volumio-tau volumio[1039]: info: Discovery: Found device Volumio-tau Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:16 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:16 volumio-tau volumio[1039]: info: Discovery: this is already registered, de8c6e8d-814c-44a8-8600-652132215e81 Aug 29 22:11:16 volumio-tau volumio[1039]: info: Discovery: Found device Volumio-tau Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:16 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:16 volumio-tau volumio[1039]: info: VolumeController:: Volume=90 Mute =false Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreStateMachine::pushState Aug 29 22:11:16 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioPushState Aug 29 22:11:16 volumio-tau volumio[1039]: info: Completed loading Core Plugins Aug 29 22:11:16 volumio-tau volumio[1039]: info: Preparing to generate the ALSA configuration file Aug 29 22:11:16 volumio-tau volumio[1039]: info: Asound.conf file unchanged, so no further update is needed Aug 29 22:11:16 volumio-tau volumio[1039]: info: Output device has changed, restarting MPD Aug 29 22:11:16 volumio-tau volumio[1039]: info: Output device has changed, restarting Shairport Sync Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:16 volumio-tau sudo[1299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 22:11:16 volumio-tau sudo[1299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:16 volumio-tau sudo[1297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 22:11:16 volumio-tau sudo[1297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:16 volumio-tau volumio[1270]: Forking 3 albumart workers Aug 29 22:11:16 volumio-tau volumio[1039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 22:11:16 volumio-tau volumio[1039]: info: ___________ START PLUGINS ___________ Aug 29 22:11:16 volumio-tau sudo[1297]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:16 volumio-tau volumio[1039]: info: ControllerMpd::onStart: Initializing MPD Aug 29 22:11:16 volumio-tau volumio[1039]: info: Creating MPD Configuration file Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 22:11:16 volumio-tau volumio[1039]: info: [1788009076648] CoreMusicLibrary::Adding element DLNAサーバー Aug 29 22:11:16 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 22:11:16 volumio-tau systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 29 22:11:16 volumio-tau systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 22:11:16 volumio-tau systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 22:11:16 volumio-tau sudo[1308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 29 22:11:16 volumio-tau sudo[1310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 22:11:16 volumio-tau sudo[1310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:16 volumio-tau sudo[1308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:16 volumio-tau volumio[1039]: info: UPNP Browser: Client initialized successfully Aug 29 22:11:16 volumio-tau sudo[1313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 22:11:16 volumio-tau sudo[1313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:16 volumio-tau sudo[1310]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:17 volumio-tau systemd[1]: mpd.service: Deactivated successfully. Aug 29 22:11:17 volumio-tau systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 22:11:17 volumio-tau systemd[1]: mpd.socket: Deactivated successfully. Aug 29 22:11:17 volumio-tau systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 22:11:17 volumio-tau systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 22:11:17 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:17 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:17 volumio-tau systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 22:11:17 volumio-tau systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 22:11:17 volumio-tau systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 22:11:17 volumio-tau sudo[1308]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:17 volumio-tau volumio[1039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 22:11:17 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:17 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:17 volumio-tau sudo[1353]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 22:11:17 volumio-tau sudo[1353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 22:11:17 volumio-tau sudo[1368]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 22:11:17 volumio-tau sudo[1353]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:18 volumio-tau volumio[1039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 22:11:18 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 22:11:18 volumio-tau volumio[1039]: info: [1788009078045] CoreMusicLibrary::Adding element Last_100 Aug 29 22:11:18 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 22:11:18 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 22:11:18 volumio-tau volumio[1039]: info: [1788009078050] CoreMusicLibrary::Adding element Webradio Aug 29 22:11:18 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 22:11:18 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 22:11:18 volumio-tau volumio[1039]: info: Initializing BBC Radios Aug 29 22:11:18 volumio-tau volumio5-onboarding[1361]: time=2026-08-29T22:11:18.530+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 22:11:18 volumio-tau volumio[1039]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Aug 29 22:11:18 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:19 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 22:11:19 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:19 volumio-tau volumio[1039]: info: Volumio Calling Home Aug 29 22:11:20 volumio-tau systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 29 22:11:20 volumio-tau systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 29 22:11:20 volumio-tau systemd[1]: setdatetime-helper.service: Consumed 1.567s CPU time. Aug 29 22:11:24 volumio-tau systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Aug 29 22:11:24 volumio-tau systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 22:11:24 volumio-tau systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 22:11:24 volumio-tau upmpdcli[1422]: Could not open config: /tmp/upmpdcli.conf Aug 29 22:11:24 volumio-tau systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 22:11:24 volumio-tau systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 22:11:28 volumio-tau volumio[1039]: info: MPD Permissions set Aug 29 22:11:28 volumio-tau volumio[1039]: info: MPD Permissions set Aug 29 22:11:28 volumio-tau volumio5-onboarding[1361]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:53194->127.0.0.1:3000: i/o timeout Aug 29 22:11:28 volumio-tau systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 22:11:28 volumio-tau systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 22:11:28 volumio-tau systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 29 22:11:28 volumio-tau systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 22:11:28 volumio-tau systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 22:11:29 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:29.315+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 22:11:36 volumio-tau mpd[1373]: 2026-08-29T22:11:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 22:11:36 volumio-tau volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 29 22:11:36 volumio-tau volumio[1039]: info: Volumio called home Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:36 volumio-tau systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 22:11:36 volumio-tau sudo[1313]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:36 volumio-tau sudo[1299]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:36 volumio-tau sudo[1425]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 22:11:36 volumio-tau sudo[1425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:36 volumio-tau sudo[1426]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 22:11:36 volumio-tau sudo[1426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:36 volumio-tau sudo[1426]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:36 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:37 volumio-tau sudo[1425]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:37 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:38 volumio-tau volumio[1039]: 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: 3 Aug 29 22:11:39 volumio-tau volumio[1039]: 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: 3 Aug 29 22:11:39 volumio-tau volumio[1039]: info: Received Get System Info Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:39 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:39 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:39 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:39.664+09:00 level=INFO msg="system info for 9b9fd04e61efe67ca7e25a64fec88c5b" deviceName=Volumio-tau deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 22:11:39 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:39.678+09:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 22:11:39 volumio-tau volumio[1039]: info: Completed starting Core Plugins Aug 29 22:11:39 volumio-tau volumio[1039]: info: ------------------------------------------- Aug 29 22:11:39 volumio-tau volumio[1039]: info: ----- MyVolumio plugins startup ---- Aug 29 22:11:39 volumio-tau volumio[1039]: info: ------------------------------------------- Aug 29 22:11:39 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 29 22:11:39 volumio-tau volumio[1039]: info: Received Get System Info Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:39 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:39 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:39 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:39 volumio-tau volumio[1039]: info: Starting Shairport Sync Aug 29 22:11:39 volumio-tau volumio[1039]: info: Starting Shairport Sync Aug 29 22:11:40 volumio-tau volumio[1039]: info: Starting Shairport Sync Aug 29 22:11:40 volumio-tau systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Aug 29 22:11:40 volumio-tau systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 22:11:40 volumio-tau systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 22:11:40 volumio-tau sudo[1478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 22:11:40 volumio-tau sudo[1478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:40 volumio-tau sudo[1480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 22:11:40 volumio-tau sudo[1480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:40 volumio-tau sudo[1476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 22:11:40 volumio-tau sudo[1476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:40 volumio-tau systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 22:11:40 volumio-tau systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 22:11:40 volumio-tau systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 22:11:40 volumio-tau systemd[1]: shairport-sync.service: Consumed 1.369s CPU time. Aug 29 22:11:40 volumio-tau systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 22:11:40 volumio-tau systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 22:11:40 volumio-tau systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 22:11:40 volumio-tau systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 22:11:40 volumio-tau sudo[1478]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:40 volumio-tau sudo[1480]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:41 volumio-tau volumio[1311]: Starting albumart workers Aug 29 22:11:41 volumio-tau systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 22:11:41 volumio-tau sudo[1476]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:41 volumio-tau volumio[1314]: Starting albumart workers Aug 29 22:11:41 volumio-tau volumio[1324]: Starting albumart workers Aug 29 22:11:41 volumio-tau volumio[1039]: error: MPD error: The expression evaluated to a falsy value: Aug 29 22:11:41 volumio-tau volumio[1039]: assert.ok(self.idling) Aug 29 22:11:41 volumio-tau volumio[1039]: error: The expression evaluated to a falsy value: Aug 29 22:11:41 volumio-tau volumio[1039]: assert.ok(self.idling) Aug 29 22:11:42 volumio-tau volumio[1039]: error: updateQueue error: null Aug 29 22:11:42 volumio-tau volumio-remote-updater[606]: Test mode disabled Aug 29 22:11:42 volumio-tau volumio-remote-updater[606]: Alpha mode disabled Aug 29 22:11:42 volumio-tau volumio-remote-updater[606]: Alpha legacy test mode disabled Aug 29 22:11:42 volumio-tau sudo[1512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 29 22:11:42 volumio-tau sudo[1512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:11:42 volumio-tau volumio[1039]: info: Shairport-Sync Started Aug 29 22:11:42 volumio-tau volumio[1039]: Error adding Membership: Error: addMembership EINVAL Aug 29 22:11:42 volumio-tau volumio[1039]: info: Shairport-Sync Started Aug 29 22:11:42 volumio-tau volumio[1039]: info: Shairport-Sync Started Aug 29 22:11:42 volumio-tau volumio[1039]: info: MPD running with PID1373 Aug 29 22:11:42 volumio-tau volumio[1039]: ,establishing connection Aug 29 22:11:42 volumio-tau sudo[1512]: pam_unix(sudo:session): session closed for user root Aug 29 22:11:43 volumio-tau volumio[1039]: info: Upmpdcli Daemon Started Aug 29 22:11:43 volumio-tau volumio[1039]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 29 22:11:43 volumio-tau volumio[1039]: error: updateQueue error: null Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 22:11:43 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:43.494+09: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" Aug 29 22:11:43 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:43.509+09: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" Aug 29 22:11:43 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:43.509+09: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" Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:43 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 22:11:43 volumio-tau volumio[1039]: info: Received Get System Info Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:43 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:43 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 22:11:43 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 22:11:43 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:43.840+09:00 level=INFO msg="enabling local network discovery" Aug 29 22:11:43 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:43.898+09:00 level=INFO msg="enabling BLE discovery" Aug 29 22:11:45 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:45.356+09:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 22:11:45 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:45.608+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.10.105:54240 Aug 29 22:11:45 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:45.690+09:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s Aug 29 22:11:45 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:45.858+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.10.105:54240 @ 0x2c01020" latency=188.411548ms timeout=20s Aug 29 22:11:45 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:45.858+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" Aug 29 22:11:46 volumio-tau volumio[1039]: info: Received Get System Info Aug 29 22:11:46 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:46 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:46 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:46 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:46 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:46 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:46 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:46.117+09:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" name=Volumio-tau Aug 29 22:11:46 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:46.602+09:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" language=ja Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.178+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=http://pushupdates.volumio.org duration=1.46980631s Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.341+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=http://plugins.volumio.org duration=1.484157713s Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.572+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=1.882040518s Aug 29 22:11:47 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.635+09:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" timezone=Asia/Tokyo Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.636+09:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" available=false connected=false macAddress= ip4Address= ip6Address= Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.654+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" available=true connected=true macAddress=d8:3a:dd:36:a1:84 ip4Address=192.168.10.106/24 ip6Address= ssid=aterm-eaf893-g Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.785+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=2.074334751s Aug 29 22:11:47 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:47.988+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=http://cddb.volumio.org duration=2.13030394s Aug 29 22:11:48 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:48.945+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://www.googleapis.com duration=3.237022428s Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.065+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://securetoken.googleapis.com duration=3.374051951s Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.104+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://functions.volumio.cloud duration=3.413574643s Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.104+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://functions.volumio.cloud duration=3.247132615s Aug 29 22:11:49 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 22:11:49 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.174+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://database.volumio.cloud duration=3.316858352s Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.174+09:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" setupComplete=true Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.243+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=3.552811275s Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.428+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=3.719584345s Aug 29 22:11:49 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:49.464+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54240 @ 0x2c01020" latency=81.100178ms timeout=10s endpoint=https://google.com duration=3.756106286s Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.021+09:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.10.105:54240 Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.022+09:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.10.105:54240 Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.031+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.10.105:54351 Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.069+09:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.073+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.10.105:54351 @ 0x2e14030" latency=30.877449ms timeout=20s Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.073+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.083+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=13.803835ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.165+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=93.807101ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.165+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=94.604499ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.182+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://google.com duration=112.520322ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.183+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://www.googleapis.com duration=113.584805ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.241+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=170.487285ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.249+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://database.volumio.cloud duration=177.656937ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.250+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://functions.volumio.cloud duration=179.309754ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.252+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://functions.volumio.cloud duration=180.311527ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.287+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=https://securetoken.googleapis.com duration=217.007397ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.337+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=http://pushupdates.volumio.org duration=265.841004ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.394+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=http://plugins.volumio.org duration=322.936453ms Aug 29 22:11:51 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:51.494+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=29.153325ms timeout=10s endpoint=http://cddb.volumio.org duration=423.458309ms Aug 29 22:11:53 volumio-tau volumio[1039]: verbose: New Socket.io Connection to 192.168.10.106 from 192.168.10.105 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 4 Aug 29 22:11:53 volumio-tau volumio[1039]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 22:11:53 volumio-tau volumio[1039]: info: Received Get System Info Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:53 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:53 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:53 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:53 volumio-tau volumio[1039]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 29 22:11:54 volumio-tau volumio[1039]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 29 22:11:54 volumio-tau volumio[1039]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 29 22:11:54 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:54.589+09:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" name=Volumio-tau Aug 29 22:11:54 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:54.592+09:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" language=ja Aug 29 22:11:55 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 29 22:11:55 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:55.478+09:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" timezone=Asia/Tokyo Aug 29 22:11:55 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:55.478+09:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" available=false connected=false macAddress= ip4Address= ip6Address= Aug 29 22:11:55 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:55.524+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" available=true connected=true macAddress=d8:3a:dd:36:a1:84 ip4Address=192.168.10.106/24 ip6Address= ssid=aterm-eaf893-g Aug 29 22:11:55 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:55.525+09:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" setupComplete=true Aug 29 22:11:56 volumio-tau volumio[1039]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 29 22:11:56 volumio-tau volumio[1039]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 22:11:56 volumio-tau volumio[1039]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\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)"} Aug 29 22:11:56 volumio-tau volumio[1039]: amixer -c 5 info | grep "FX-D03J" Aug 29 22:11:56 volumio-tau volumio[1039]: Card sysdefault:5 'FXD03J'/'FX AUDIO FX-D03J at usb-3f980000.usb-1.3, full speed' Aug 29 22:11:56 volumio-tau volumio[1039]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 29 22:11:56 volumio-tau volumio[1039]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 22:11:56 volumio-tau volumio[1039]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\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)"} Aug 29 22:11:56 volumio-tau volumio[1039]: amixer -c 5 info | grep "FX-D03J" Aug 29 22:11:57 volumio-tau volumio[1039]: Card sysdefault:5 'FXD03J'/'FX AUDIO FX-D03J at usb-3f980000.usb-1.3, full speed' Aug 29 22:11:57 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:57.048+09:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" selectedOutputId=5 Aug 29 22:11:57 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:57.048+09:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" selectedOutputId=5 Aug 29 22:11:57 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:57.050+09:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2c01020" event=SERVER_EVENT_TYPE_AUDIO_OUTPUTS_CHANGED error="no addresses to write to" Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 22:11:57 volumio-tau volumio[1039]: info: Received Get System Info Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:57 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:57 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:57 volumio-tau volumio[1039]: info: Received Get System Info Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:57 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:57 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:57 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:57 volumio-tau volumio[1039]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 29 22:11:58 volumio-tau volumio[1039]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 29 22:11:58 volumio-tau volumio[1039]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.376+09:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" currentVersion=4.119 latestVersion=4.119 Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.377+09:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.10.105:54351 @ 0x2e14030" status=UPDATE_STATUS_NONE progress=0 Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.378+09:00 level=INFO msg="emitting user changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" userId= Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.378+09:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" providers=3 Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.380+09:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" currentVersion=4.119 latestVersion=4.119 Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.380+09:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2c01020" event=SERVER_EVENT_TYPE_SOFTWARE_INFO_CHANGED error="no addresses to write to" Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.380+09:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.10.105:54240 @ 0x2c01020" status=UPDATE_STATUS_NONE progress=0 Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.380+09:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2c01020" event=SERVER_EVENT_TYPE_SOFTWARE_UPDATE_PROGRESS error="no addresses to write to" Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.380+09:00 level=INFO msg="emitting user changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" userId= Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.380+09:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2c01020" event=SERVER_EVENT_TYPE_USER_CHANGED error="no addresses to write to" Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.381+09:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.10.105:54240 @ 0x2c01020" providers=3 Aug 29 22:11:58 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:11:58.381+09:00 level=ERROR msg="failed to send event" component=server dst=" @ 0x2c01020" event=SERVER_EVENT_TYPE_MUSIC_PROVIDERS_CHANGED error="no addresses to write to" Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:11:59 volumio-tau volumio[1039]: info: Discovery: Getting this device information Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::volumioGetState Aug 29 22:11:59 volumio-tau volumio[1039]: info: CorePlayQueue::getTrack 0 Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:11:59 volumio-tau volumio[1039]: verbose: New Socket.io Connection to 192.168.10.106 from 192.168.10.105 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 Aug 29 22:11:59 volumio-tau volumio[1039]: error: MyVolumio Plugin failed to start in a timely fashion Aug 29 22:11:59 volumio-tau volumio[1039]: [Metrics] CommandRouter: 56s 619.51ms Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::volumiosetStartupVolume Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:11:59 volumio-tau volumio[1039]: info: CoreCommandRouter::Close All Modals sent Aug 29 22:12:00 volumio-tau volumio[1039]: info: CoreCommandRouter::Close All Modals sent Aug 29 22:12:00 volumio-tau upmpdcli[1623]: writing RSA key Aug 29 22:12:00 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 22:12:00 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:00.158+09:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.10.105:54351 @ 0x2e14030" plugins=0 Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 29 22:12:00 volumio-tau volumio[1039]: info: Adding plugin bluetooth to MyMusic Plugins Aug 29 22:12:00 volumio-tau volumio[1039]: info: Adding plugin multiroom to MyMusic Plugins Aug 29 22:12:00 volumio-tau volumio[1039]: info: Adding plugin metavolumio to MyMusic Plugins Aug 29 22:12:00 volumio-tau volumio[1039]: info: Adding plugin cd_controller to MyMusic Plugins Aug 29 22:12:00 volumio-tau volumio[1039]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 29 22:12:00 volumio-tau volumio[1039]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 29 22:12:00 volumio-tau volumio[1039]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 29 22:12:00 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.312+09:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.10.105:54351 @ 0x2e14030" latency=29.387665ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.342+09:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.363+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=18.020147ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.452+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://google.com duration=108.239218ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.452+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=107.638228ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.452+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=108.277604ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.463+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://www.googleapis.com duration=120.500446ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.514+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=170.5814ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.522+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://functions.volumio.cloud duration=179.437358ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.524+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://database.volumio.cloud duration=179.123191ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.542+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://functions.volumio.cloud duration=197.372194ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.562+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=https://securetoken.googleapis.com duration=218.807557ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.608+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=http://pushupdates.volumio.org duration=264.141728ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.671+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=http://plugins.volumio.org duration=326.204117ms Aug 29 22:12:02 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:02.771+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=31.488647ms timeout=10s endpoint=http://cddb.volumio.org duration=427.276131ms Aug 29 22:12:05 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:05.859+09:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.10.105:54240 @ 0x2c01020" latency=188.411548ms timeout=20s error="failed to get available plugins: could not get available plugins: could not check MyVolumio login status: context deadline exceeded" Aug 29 22:12:05 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:05.861+09:00 level=ERROR msg="failed to send response" component=server dst=" @ 0x2c01020" id=704594297 status=STATUS_UNKNOWN error="no addresses to write to" Aug 29 22:12:11 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:11.073+09:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.10.105:54351 @ 0x2e14030" latency=30.877449ms timeout=20s error="could not get player state: failed to get current state: context deadline exceeded" Aug 29 22:12:13 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 29 22:12:13 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 29 22:12:13 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:12:13 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:12:13 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:12:13 volumio-tau volumio[1039]: info: Starting MyVolumio Remote Streaming Endpoints Aug 29 22:12:13 volumio-tau volumio[1039]: info: MyVolumio not started Aug 29 22:12:13 volumio-tau volumio[1039]: info: Initializing device activation check Aug 29 22:12:13 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 22:12:13 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 29 22:12:13 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 29 22:12:19 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 29 22:12:19 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 29 22:12:19 volumio-tau volumio[1039]: info: Streaming services startup Aug 29 22:12:20 volumio-tau volumio[1039]: info: Starting Streaming Daemon Aug 29 22:12:20 volumio-tau volumio[1039]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 29 22:12:20 volumio-tau sudo[1656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 22:12:20 volumio-tau sudo[1656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:12:20 volumio-tau sudo[1656]: pam_unix(sudo:session): session closed for user root Aug 29 22:12:20 volumio-tau volumio[1039]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 29 22:12:20 volumio-tau volumio[1039]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 22:12:20 volumio-tau volumio[1039]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\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)"} Aug 29 22:12:20 volumio-tau volumio[1039]: amixer -c 5 info | grep "FX-D03J" Aug 29 22:12:21 volumio-tau volumio[1039]: Card sysdefault:5 'FXD03J'/'FX AUDIO FX-D03J at usb-3f980000.usb-1.3, full speed' Aug 29 22:12:21 volumio-tau volumio[1039]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 29 22:12:21 volumio-tau volumio[1039]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 29 22:12:21 volumio-tau volumio[1039]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\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)"} Aug 29 22:12:21 volumio-tau volumio[1039]: amixer -c 5 info | grep "FX-D03J" Aug 29 22:12:21 volumio-tau volumio[1039]: Card sysdefault:5 'FXD03J'/'FX AUDIO FX-D03J at usb-3f980000.usb-1.3, full speed' Aug 29 22:12:21 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 29 22:12:21 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 22:12:21 volumio-tau volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 29 22:12:21 volumio-tau volumio[1039]: info: BOOT COMPLETED Aug 29 22:12:21 volumio-tau volumio[1039]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 22:12:21 volumio-tau volumio[1039]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Aug 29 22:12:21 volumio-tau volumio[1039]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Aug 29 22:12:21 volumio-tau volumio[1039]: at new NodeError (node:internal/errors:405:5) Aug 29 22:12:21 volumio-tau volumio[1039]: at assert (node:internal/assert:14:11) Aug 29 22:12:21 volumio-tau volumio[1039]: at internalConnectMultiple (node:net:1118:3) Aug 29 22:12:21 volumio-tau volumio[1039]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Aug 29 22:12:21 volumio-tau volumio[1039]: at listOnTimeout (node:internal/timers:575:11) Aug 29 22:12:21 volumio-tau volumio[1039]: at process.processTimers (node:internal/timers:514:7) { Aug 29 22:12:21 volumio-tau volumio[1039]: code: 'ERR_INTERNAL_ASSERTION' Aug 29 22:12:21 volumio-tau volumio[1039]: } Aug 29 22:12:21 volumio-tau volumio[1039]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.249+09:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.10.105:54351 @ 0x2e14030" latency=130.519868ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.277+09:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.288+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=10.360129ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.371+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=93.841527ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.371+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=93.768142ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.385+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://google.com duration=106.628277ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.393+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://www.googleapis.com duration=114.456733ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.450+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=171.781142ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.462+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://database.volumio.cloud duration=181.347311ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.464+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://functions.volumio.cloud duration=184.29987ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.467+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://functions.volumio.cloud duration=188.281962ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.490+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=https://securetoken.googleapis.com duration=211.639258ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.545+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=http://pushupdates.volumio.org duration=265.296055ms Aug 29 22:12:31 volumio-tau sudo[1701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 22:11' Aug 29 22:12:31 volumio-tau sudo[1701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.817+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=http://plugins.volumio.org duration=537.507958ms Aug 29 22:12:31 volumio-tau volumio5-onboarding[1440]: time=2026-08-29T22:12:31.889+09:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.10.105:54351 @ 0x2e14030" latency=28.273862ms timeout=10s endpoint=http://cddb.volumio.org duration=610.860739ms 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"