-- Logs begin at Sat 2026-04-11 20:31:35 JST, end at Sun 2026-04-12 09:15:09 JST. -- Apr 12 09:14:09 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:09.053+09:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:59824->127.0.0.1:3000: i/o timeout" Apr 12 09:14:11 volumio4 volumio[1291]: STREAMING PROXY: Starting server on port 3245 Apr 12 09:14:11 volumio4 volumio[1291]: Node JS runtime: 14 Apr 12 09:14:13 volumio4 volumio[1291]: <--- Last few GCs ---> Apr 12 09:14:13 volumio4 volumio[1291]: [1291:0x3dee908] 112083 ms: Scavenge 100.2 (106.6) -> 99.9 (106.6) MB, 2.8 / 0.0 ms (average mu = 0.917, current mu = 0.902) allocation failure Apr 12 09:14:13 volumio4 volumio[1291]: [1291:0x3dee908] 112893 ms: Scavenge 107.3 (113.8) -> 107.1 (113.8) MB, 3.8 / 0.0 ms (average mu = 0.917, current mu = 0.902) allocation failure Apr 12 09:14:13 volumio4 volumio[1291]: [1291:0x3dee908] 113066 ms: Scavenge 114.6 (121.2) -> 114.6 (121.2) MB, 11.2 / 0.0 ms (average mu = 0.917, current mu = 0.902) allocation failure Apr 12 09:14:13 volumio4 volumio[1291]: <--- JS stacktrace ---> Apr 12 09:14:13 volumio4 volumio[1291]: FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory Apr 12 09:14:13 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 12 09:14:13 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 12 09:14:13 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:13.256+09:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:45000->127.0.0.1:3000: read: connection reset by peer" Apr 12 09:14:13 volumio4 systemd[1]: volumio.service: Main process exited, code=killed, status=6/ABRT Apr 12 09:14:13 volumio4 systemd[1]: volumio.service: Failed with result 'signal'. Apr 12 09:14:13 volumio4 systemd[1]: Started dynamicswap service. Apr 12 09:14:13 volumio4 systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Apr 12 09:14:13 volumio4 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Apr 12 09:14:13 volumio4 systemd[1]: Stopped Volumio Backend Module. Apr 12 09:14:13 volumio4 systemd[1]: Started Volumio Backend Module. Apr 12 09:14:13 volumio4 systemd[1]: dynamicswap.service: Succeeded. Apr 12 09:14:14 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:14.376+09:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 12 09:14:15 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:15.379+09:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 12 09:14:16 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:16.390+09:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 12 09:14:17 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:17.401+09:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 12 09:14:18 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:18] [info] asio async_connect error: system:111 (Connection refused) Apr 12 09:14:18 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:18] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 12 09:14:18 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:18] [error] handle_connect error: Underlying Transport Error Apr 12 09:14:18 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:18.410+09:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 12 09:14:19 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:19.417+09:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 12 09:14:23 volumio4 volumio[1670]: info: ------------------------------------------- Apr 12 09:14:23 volumio4 volumio[1670]: info: ----- Volumio3 ---- Apr 12 09:14:23 volumio4 volumio[1670]: info: ------------------------------------------- Apr 12 09:14:23 volumio4 volumio[1670]: info: ----- System startup ---- Apr 12 09:14:23 volumio4 volumio[1670]: info: ------------------------------------------- Apr 12 09:14:25 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:25] [connect] Successful connection Apr 12 09:14:26 volumio4 volumio[1670]: info: MYVOLUMIO Environment detected Apr 12 09:14:27 volumio4 volumio[1670]: info: Plugin folders cleanup Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning into folder /volumio/app/plugins/ Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning category audio_interface Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning category miscellanea Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning category music_service Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning category plugins.json Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning category system_controller Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning category user_interface Apr 12 09:14:27 volumio4 volumio[1670]: info: Scanning into folder /data/plugins/ Apr 12 09:14:27 volumio4 volumio[1670]: info: Plugin folders cleanup completed Apr 12 09:14:27 volumio4 volumio[1670]: info: ------------------------------------------- Apr 12 09:14:27 volumio4 volumio[1670]: info: ----- Core plugins startup ---- Apr 12 09:14:27 volumio4 volumio[1670]: info: ------------------------------------------- Apr 12 09:14:27 volumio4 volumio[1670]: info: Loading plugins from folder /volumio/app/plugins/ Apr 12 09:14:27 volumio4 volumio[1670]: info: Adding plugin upnp to MyMusic Plugins Apr 12 09:14:27 volumio4 volumio[1670]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 12 09:14:27 volumio4 volumio[1670]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 12 09:14:27 volumio4 volumio[1670]: info: Loading plugins from folder /data/plugins/ Apr 12 09:14:27 volumio4 volumio[1670]: info: Loading plugin "system"... Apr 12 09:14:27 volumio4 volumio[1670]: info: Loading plugin "appearance"... Apr 12 09:14:30 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:30.430+09:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:58458->127.0.0.1:3000: i/o timeout" Apr 12 09:14:32 volumio4 volumio[1670]: info: Loading plugin "network"... Apr 12 09:14:32 volumio4 volumio[1670]: info: Refreshing Cached IP Addresses Apr 12 09:14:32 volumio4 volumio[1670]: info: Loading plugin "services"... Apr 12 09:14:32 volumio4 volumio[1670]: info: Loading plugin "volumio5onboarding"... Apr 12 09:14:33 volumio4 sudo[1698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 09:14:33 volumio4 sudo[1700]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 09:14:33 volumio4 sudo[1707]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 12 09:14:33 volumio4 sudo[1707]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:33 volumio4 sudo[1700]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:33 volumio4 sudo[1698]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:33 volumio4 sudo[1700]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:33 volumio4 volumio[1670]: info: Loading plugin "alsa_controller"... Apr 12 09:14:33 volumio4 sudo[1698]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:34 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 09:14:34 volumio4 volumio[1670]: info: Loading plugin "wizard"... Apr 12 09:14:34 volumio4 volumio[1670]: info: Loading plugin "networkfs"... Apr 12 09:14:34 volumio4 sudo[1707]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:34 volumio4 volumio[1670]: info: Cannot mount NAS album at system boot, trial number 1 ,retrying in 5 seconds Apr 12 09:14:34 volumio4 volumio[1670]: info: Cannot mount NAS FLAC at system boot, trial number 1 ,retrying in 5 seconds Apr 12 09:14:34 volumio4 volumio[1670]: info: Starting Udev Watcher for removable devices Apr 12 09:14:34 volumio4 volumio[1670]: info: Ignoring mount for partition: boot Apr 12 09:14:34 volumio4 volumio[1670]: info: Ignoring mount for partition: volumio Apr 12 09:14:34 volumio4 volumio[1670]: info: Ignoring mount for partition: volumio_data Apr 12 09:14:34 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 09:14:34 volumio4 volumio[1670]: info: Loading plugin "volumio_command_line_client"... Apr 12 09:14:34 volumio4 volumio[1670]: info: Loading plugin "upnp"... Apr 12 09:14:34 volumio4 volumio[1670]: info: [1775952874605] Starting Upmpd Daemon Apr 12 09:14:34 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 09:14:34 volumio4 volumio[1670]: info: Loading plugin "my_music"... Apr 12 09:14:34 volumio4 volumio[1670]: info: Loading plugin "mpd"... Apr 12 09:14:36 volumio4 volumio[1670]: info: Loading plugin "upnp_browser"... Apr 12 09:14:37 volumio4 volumio[1670]: info: Starting UPNP Browser Apr 12 09:14:37 volumio4 volumio[1670]: info: Loading plugin "alarm-clock"... Apr 12 09:14:39 volumio4 volumio[1670]: info: Loading plugin "airplay_emulation"... Apr 12 09:14:39 volumio4 volumio[1670]: info: Starting Shairport Sync Apr 12 09:14:39 volumio4 volumio[1670]: info: Loading plugin "last_100"... Apr 12 09:14:39 volumio4 volumio[1670]: info: Loading plugin "webradio"... Apr 12 09:14:39 volumio4 volumio[1670]: info: Loading plugin "i2s_dacs"... Apr 12 09:14:39 volumio4 volumio[1670]: info: Loading plugin "volumiodiscovery"... Apr 12 09:14:40 volumio4 volumio[1670]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 09:14:40 volumio4 node[1670]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 09:14:40 volumio4 node[1670]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 09:14:40 volumio4 volumio[1670]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 09:14:40 volumio4 volumio[1670]: *** WARNING *** For more information see Apr 12 09:14:40 volumio4 volumio[1670]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 09:14:40 volumio4 volumio[1670]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 09:14:40 volumio4 volumio[1670]: *** WARNING *** For more information see Apr 12 09:14:40 volumio4 node[1670]: *** WARNING *** For more information see Apr 12 09:14:40 volumio4 node[1670]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 09:14:40 volumio4 node[1670]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 09:14:40 volumio4 node[1670]: *** WARNING *** For more information see Apr 12 09:14:40 volumio4 volumio[1670]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 12 09:14:40 volumio4 volumio[1670]: info: Discovery: Started advertising with name: Volumio4 Apr 12 09:14:40 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 09:14:40 volumio4 volumio[1670]: info: Loading plugin "outputs"... Apr 12 09:14:40 volumio4 volumio[1670]: info: Loading plugin "albumart"... Apr 12 09:14:40 volumio4 volumio[1670]: info: Plugin example_plugin is not enabled Apr 12 09:14:40 volumio4 volumio[1670]: info: Loading plugin "inputs"... Apr 12 09:14:40 volumio4 volumio[1670]: info: Loading plugin "updater_comm"... Apr 12 09:14:40 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:40] [connect] Successful connection Apr 12 09:14:41 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:41.435+09:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:59244->127.0.0.1:3000: i/o timeout" Apr 12 09:14:42 volumio4 volumio[1670]: info: Plugin mpdemulation is not enabled Apr 12 09:14:42 volumio4 volumio[1670]: info: Loading plugin "rest_api"... Apr 12 09:14:42 volumio4 volumio[1670]: info: Loading plugin "websocket"... Apr 12 09:14:42 volumio4 volumio[1670]: info: Starting Socket.io Server version 2.3.0 Apr 12 09:14:43 volumio4 volumio[1670]: info: Loading i18n strings for locale ja Apr 12 09:14:43 volumio4 volumio[1670]: Updating browse sources language Apr 12 09:14:43 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 09:14:44 volumio4 volumio[1670]: Forking 1 albumart workers Apr 12 09:14:44 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:14:44.781+09:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Apr 12 09:14:45 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 09:14:45 volumio4 volumio[1670]: info: CoreCommandRouter::initPlayerControls Apr 12 09:14:45 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 09:14:45 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 09:14:45 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 09:14:45 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 09:14:45 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 09:14:46 volumio4 volumio[1670]: Express server listening on port 3000 Apr 12 09:14:46 volumio4 volumio[1670]: [Metrics] WebUI: 26s 53.12ms Apr 12 09:14:46 volumio4 volumio[1670]: info: CoreStateMachine::resetVolumioState Apr 12 09:14:46 volumio4 volumio[1670]: info: CoreStateMachine::getcurrentVolume Apr 12 09:14:46 volumio4 volumio[1670]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 09:14:46 volumio4 volumio[1670]: info: Cannot mount NAS album at system boot, trial number 2 ,retrying in 5 seconds Apr 12 09:14:46 volumio4 volumio[1670]: info: Cannot mount NAS FLAC at system boot, trial number 2 ,retrying in 5 seconds Apr 12 09:14:46 volumio4 sudo[1800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 09:14:46 volumio4 sudo[1800]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:46 volumio4 sudo[1802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 09:14:46 volumio4 sudo[1802]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:47 volumio4 sudo[1800]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:47 volumio4 sudo[1802]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:47 volumio4 volumio[1670]: info: Volumio Network Manager: Network status updated: 2 Apr 12 09:14:48 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:48 volumio4 volumio[1670]: info: VolumeController:: Volume=76 Mute =false Apr 12 09:14:48 volumio4 volumio[1670]: info: CoreStateMachine::pushState Apr 12 09:14:48 volumio4 volumio[1670]: info: CorePlayQueue::getTrack 0 Apr 12 09:14:48 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 09:14:48 volumio4 volumio[1670]: info: CoreCommandRouter::volumioPushState Apr 12 09:14:48 volumio4 volumio[1670]: info: CoreStateMachine::updateTrackBlock Apr 12 09:14:48 volumio4 volumio[1670]: info: CorePlayQueue::getTrackBlock Apr 12 09:14:48 volumio4 volumio[1670]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 09:14:49 volumio4 volumio[1670]: info: Reloading queue from file Apr 12 09:14:49 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:49 volumio4 volumio[1670]: info: Setting Device type: Raspberry PI Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreStateMachine::setRepeat true single undefined Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreStateMachine::pushState Apr 12 09:14:49 volumio4 volumio[1670]: info: CorePlayQueue::getTrack 0 Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreCommandRouter::volumioPushState Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreStateMachine::setRandom true Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreStateMachine::pushState Apr 12 09:14:49 volumio4 volumio[1670]: info: CorePlayQueue::getTrack 0 Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 09:14:49 volumio4 volumio[1670]: info: CoreCommandRouter::volumioPushState Apr 12 09:14:49 volumio4 volumio[1670]: info: Discovery: adding afa2c322-8c02-4a87-a62c-cdbf1774f460 Apr 12 09:14:49 volumio4 volumio[1670]: info: Discovery: Found device Volumio2 Apr 12 09:14:50 volumio4 volumio[1670]: info: Discovery: Connecting to remote: 192.168.10.5 Apr 12 09:14:50 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:50 volumio4 volumio[1670]: info: VolumeController:: Volume=76 Mute =false Apr 12 09:14:50 volumio4 volumio[1670]: info: CoreStateMachine::pushState Apr 12 09:14:50 volumio4 volumio[1670]: info: CorePlayQueue::getTrack 0 Apr 12 09:14:50 volumio4 volumio[1670]: info: CoreCommandRouter::volumioPushState Apr 12 09:14:50 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:50 volumio4 sudo[1817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 12 09:14:50 volumio4 sudo[1817]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:50 volumio4 volumio[1670]: info: Discovery: adding d6bd8456-a109-4e3f-b352-2ddf7c69adbc Apr 12 09:14:50 volumio4 volumio[1670]: info: Discovery: Found device Volumio4 Apr 12 09:14:50 volumio4 volumio[1670]: info: CoreCommandRouter::volumioGetState Apr 12 09:14:50 volumio4 volumio[1670]: info: CorePlayQueue::getTrack 0 Apr 12 09:14:51 volumio4 sudo[1817]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:51 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:51 volumio4 volumio[1670]: info: Completed loading Core Plugins Apr 12 09:14:51 volumio4 volumio[1670]: info: Preparing to generate the ALSA configuration file Apr 12 09:14:51 volumio4 volumio[1670]: info: Upmpdcli Daemon Started Apr 12 09:14:51 volumio4 volumio[1670]: info: Cannot mount NAS album at system boot, trial number 3 ,retrying in 5 seconds Apr 12 09:14:51 volumio4 volumio[1670]: info: Cannot mount NAS FLAC at system boot, trial number 3 ,retrying in 5 seconds Apr 12 09:14:51 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:51 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:51 volumio4 volumio[1670]: 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: 1 Apr 12 09:14:51 volumio4 volumio[1670]: info: Asound.conf file unchanged, so no further update is needed Apr 12 09:14:51 volumio4 volumio[1670]: info: Output device has changed, restarting MPD Apr 12 09:14:52 volumio4 volumio[1670]: info: Output device has changed, restarting Shairport Sync Apr 12 09:14:52 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 09:14:52 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 09:14:52 volumio4 sudo[1820]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 09:14:52 volumio4 sudo[1820]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:52 volumio4 sudo[1820]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:52 volumio4 sudo[1822]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 09:14:52 volumio4 sudo[1822]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:52 volumio4 systemd[1]: Stopping Music Player Daemon... Apr 12 09:14:52 volumio4 volumio[1670]: Starting albumart workers Apr 12 09:14:52 volumio4 volumio[1670]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 09:14:52 volumio4 volumio[1670]: info: ___________ START PLUGINS ___________ Apr 12 09:14:53 volumio4 volumio[1670]: info: ControllerMpd::onStart: Initializing MPD Apr 12 09:14:53 volumio4 volumio[1670]: info: Creating MPD Configuration file Apr 12 09:14:53 volumio4 systemd[1]: mpd.service: Succeeded. Apr 12 09:14:53 volumio4 systemd[1]: Stopped Music Player Daemon. Apr 12 09:14:53 volumio4 systemd[1]: Starting Music Player Daemon... Apr 12 09:14:53 volumio4 sudo[1829]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 12 09:14:53 volumio4 sudo[1829]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:53 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 09:14:53 volumio4 volumio[1670]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 09:14:53 volumio4 volumio[1670]: info: [1775952893666] CoreMusicLibrary::Adding element DLNAサーバー Apr 12 09:14:53 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 09:14:53 volumio4 sudo[1831]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 09:14:53 volumio4 sudo[1831]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:53 volumio4 sudo[1829]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:54 volumio4 sudo[1831]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:54 volumio4 volumio[1670]: info: UPNP Browser: Client initialized successfully Apr 12 09:14:54 volumio4 sudo[1835]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 09:14:54 volumio4 sudo[1835]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:54 volumio4 sudo[1832]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 09:14:54 volumio4 sudo[1832]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:54 volumio4 sudo[1832]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:54 volumio4 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 12 09:14:54 volumio4 systemd[1]: mpd.service: Succeeded. Apr 12 09:14:54 volumio4 systemd[1]: Stopped Music Player Daemon. Apr 12 09:14:54 volumio4 systemd[1]: Starting Music Player Daemon... Apr 12 09:14:54 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 09:14:54 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 09:14:55 volumio4 sudo[1850]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 09:14:55 volumio4 sudo[1850]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:14:55 volumio4 sudo[1850]: pam_unix(sudo:session): session closed for user root Apr 12 09:14:55 volumio4 volumio[1670]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 09:14:55 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 09:14:55 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 09:14:55 volumio4 volumio-remote-updater[397]: [2026-04-12 09:14:55] [connect] Successful connection Apr 12 09:14:56 volumio4 volumio[1670]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 09:14:56 volumio4 volumio[1670]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 09:14:56 volumio4 volumio[1670]: info: [1775952896215] CoreMusicLibrary::Adding element Last_100 Apr 12 09:14:56 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 09:14:56 volumio4 volumio[1670]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 09:14:56 volumio4 volumio[1670]: info: [1775952896285] CoreMusicLibrary::Adding element Webradio Apr 12 09:14:56 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 09:14:56 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 09:14:56 volumio4 volumio[1670]: info: Initializing BBC Radios Apr 12 09:14:56 volumio4 volumio[1670]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Apr 12 09:14:56 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 09:14:57 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 09:14:57 volumio4 volumio[1670]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 09:14:57 volumio4 volumio[1670]: info: Volumio Calling Home Apr 12 09:15:01 volumio4 volumio[1670]: info: Cannot mount NAS album at system boot, trial number 4 ,retrying in 5 seconds Apr 12 09:15:01 volumio4 volumio[1670]: info: Cannot mount NAS FLAC at system boot, trial number 4 ,retrying in 5 seconds Apr 12 09:15:01 volumio4 volumio[1670]: verbose: New Socket.io Connection to 192.168.10.19:3000 from 192.168.10.5 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 12 09:15:01 volumio4 volumio5-onboarding[1057]: time=2026-04-12T09:15:01.822+09:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:51594->127.0.0.1:3000: i/o timeout" Apr 12 09:15:02 volumio4 volumio[1670]: info: MPD Permissions set Apr 12 09:15:02 volumio4 volumio[1670]: info: MPD Permissions set Apr 12 09:15:03 volumio4 volumio[1670]: info: Apr 12 09:15:03 volumio4 volumio[1670]: ---------------------------- Client requests Volumio play at index 55 Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreCommandRouter::volumioPlay Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreStateMachine::play index 55 Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreStateMachine::stop Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreStateMachine::play index undefined Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 09:15:03 volumio4 volumio[1670]: info: CorePlayQueue::getTrack 55 Apr 12 09:15:03 volumio4 volumio[1670]: info: CoreStateMachine::startPlaybackTimer Apr 12 09:15:03 volumio4 volumio[1670]: info: CorePlayQueue::getTrack 55 Apr 12 09:15:03 volumio4 volumio[1670]: info: [1775952903243] ControllerWebradio::clearAddPlayTrack Apr 12 09:15:03 volumio4 volumio[1670]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 09:15:03 volumio4 volumio[1670]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 09:15:03 volumio4 volumio[1670]: TypeError: Cannot read property 'then' of undefined Apr 12 09:15:03 volumio4 volumio[1670]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Apr 12 09:15:03 volumio4 volumio[1670]: at ControllerWebradio.clearAddPlayTrack (/volumio/app/plugins/music_service/webradio/index.js:485:25) Apr 12 09:15:03 volumio4 volumio[1670]: at Promise._successFn (/volumio/app/statemachine.js:1028:24) Apr 12 09:15:03 volumio4 volumio[1670]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 12 09:15:03 volumio4 volumio[1670]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 12 09:15:03 volumio4 volumio[1670]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 09:15:09 volumio4 sudo[1908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-12 09:14 Apr 12 09:15:09 volumio4 sudo[1908]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 09:15:09 volumio4 mpd[1859]: Apr 12 09:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"