Oct 12 19:02:03 volumio sshd[2465]: Accepted password for volumio from 192.168.1.118 port 61556 ssh2 Oct 12 19:02:03 volumio sshd[2465]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Oct 12 19:02:03 volumio systemd-logind[709]: New session 4 of user volumio. Oct 12 19:02:03 volumio systemd[1]: Started session-4.scope - Session 4 of User volumio. Oct 12 19:02:04 volumio sshd[2465]: pam_env(sshd:session): deprecated reading of user environment enabled Oct 12 19:02:08 volumio volumio5-onboarding[2457]: 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:43300->127.0.0.1:3000: i/o timeout Oct 12 19:02:08 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:08 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:02:08 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 39. Oct 12 19:02:08 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:08 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:08 volumio volumio5-onboarding[2497]: time=2026-10-12T19:02:08.442+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:02:10 volumio volumio-remote-updater[715]: [2026-10-12 19:02:10] [connect] Successful connection Oct 12 19:02:18 volumio volumio5-onboarding[2497]: 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:42268->127.0.0.1:3000: i/o timeout Oct 12 19:02:18 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:18 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:02:18 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 40. Oct 12 19:02:18 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:18 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:18 volumio volumio5-onboarding[2520]: time=2026-10-12T19:02:18.692+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:02:25 volumio volumio-remote-updater[715]: [2026-10-12 19:02:25] [connect] Successful connection Oct 12 19:02:28 volumio volumio5-onboarding[2520]: 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:40420->127.0.0.1:3000: i/o timeout Oct 12 19:02:28 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:28 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:02:28 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 41. Oct 12 19:02:28 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:28 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:28 volumio volumio5-onboarding[2544]: time=2026-10-12T19:02:28.962+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:02:38 volumio volumio5-onboarding[2544]: 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:39886->127.0.0.1:3000: i/o timeout Oct 12 19:02:38 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:38 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:02:39 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 42. Oct 12 19:02:39 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:39 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:39 volumio volumio5-onboarding[2567]: time=2026-10-12T19:02:39.232+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:02:40 volumio volumio-remote-updater[715]: [2026-10-12 19:02:40] [connect] Successful connection Oct 12 19:02:49 volumio volumio5-onboarding[2567]: 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:44754->127.0.0.1:3000: i/o timeout Oct 12 19:02:49 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:49 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:02:49 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 43. Oct 12 19:02:49 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:49 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:49 volumio volumio5-onboarding[2589]: time=2026-10-12T19:02:49.472+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:02:55 volumio volumio-remote-updater[715]: [2026-10-12 19:02:55] [connect] Successful connection Oct 12 19:02:59 volumio volumio5-onboarding[2589]: 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:56290->127.0.0.1:3000: i/o timeout Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 44. Oct 12 19:02:59 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:59 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:59 volumio volumio5-onboarding[2612]: time=2026-10-12T19:02:59.694+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:02:59 volumio sudo[2613]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/systemctl restart volumio.service Oct 12 19:02:59 volumio sudo[2613]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Oct 12 19:02:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 19:02:59 volumio systemd[1]: Stopping volumio.service - Volumio Backend Module... Oct 12 19:02:59 volumio volumio-remote-updater[715]: [2026-10-12 19:02:59] [error] handle_read_http_response error: asio.system:104 (Connection reset by peer) Oct 12 19:02:59 volumio volumio-remote-updater[715]: [2026-10-12 19:02:59] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Oct 12 19:02:59 volumio volumio5-onboarding[2612]: 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:35280->127.0.0.1:3000: read: connection reset by peer Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:02:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 19:02:59 volumio systemd[1]: volumio.service: Deactivated successfully. Oct 12 19:02:59 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 19:02:59 volumio systemd[1]: volumio.service: Consumed 13min 58.150s CPU time. Oct 12 19:02:59 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 19:02:59 volumio sudo[2613]: pam_unix(sudo:session): session closed for user root Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 45. Oct 12 19:02:59 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:59 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:02:59 volumio volumio5-onboarding[2656]: time=2026-10-12T19:02:59.938+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:02:59 volumio volumio5-onboarding[2656]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:02:59 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 46. Oct 12 19:03:00 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:00 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:00 volumio volumio5-onboarding[2673]: time=2026-10-12T19:03:00.224+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:03:00 volumio volumio5-onboarding[2673]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 47. Oct 12 19:03:00 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:00 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:00 volumio volumio5-onboarding[2681]: time=2026-10-12T19:03:00.456+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:03:00 volumio volumio5-onboarding[2681]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 48. Oct 12 19:03:00 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:00 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:00 volumio volumio5-onboarding[2689]: time=2026-10-12T19:03:00.725+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 12 19:03:00 volumio volumio5-onboarding[2689]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: dial tcp 127.0.0.1:3000: connect: connection refused Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 49. Oct 12 19:03:00 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Start request repeated too quickly. Oct 12 19:03:00 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:03:00 volumio systemd[1]: Failed to start volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:01 volumio volumio[2654]: info: ------------------------------------------- Oct 12 19:03:01 volumio volumio[2654]: info: ----- Volumio3 ---- Oct 12 19:03:01 volumio volumio[2654]: info: ------------------------------------------- Oct 12 19:03:01 volumio volumio[2654]: info: ----- System startup ---- Oct 12 19:03:01 volumio volumio[2654]: info: ------------------------------------------- Oct 12 19:03:02 volumio volumio[2654]: info: MYVOLUMIO Environment detected Oct 12 19:03:02 volumio volumio[2654]: info: Configured plugin system_controller/sphereaudio cannot be loaded. Removing from configuration Oct 12 19:03:02 volumio volumio[2654]: info: Plugin folders cleanup Oct 12 19:03:02 volumio volumio[2654]: info: Scanning into folder /volumio/app/plugins/ Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category audio_interface Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category miscellanea Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category music_service Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category plugins.json Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category system_controller Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category user_interface Oct 12 19:03:02 volumio volumio[2654]: info: Scanning into folder /data/plugins/ Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category music_service Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category system_controller Oct 12 19:03:02 volumio volumio[2654]: info: Scanning category user_interface Oct 12 19:03:02 volumio volumio[2654]: info: Plugin folders cleanup completed Oct 12 19:03:02 volumio volumio[2654]: info: ------------------------------------------- Oct 12 19:03:02 volumio volumio[2654]: info: ----- Core plugins startup ---- Oct 12 19:03:02 volumio volumio[2654]: info: ------------------------------------------- Oct 12 19:03:02 volumio volumio[2654]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 19:03:02 volumio volumio[2654]: info: Adding plugin upnp to MyMusic Plugins Oct 12 19:03:02 volumio volumio[2654]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 19:03:02 volumio volumio[2654]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 19:03:02 volumio volumio[2654]: info: Loading plugins from folder /data/plugins/ Oct 12 19:03:02 volumio volumio[2654]: info: Loading plugin "system"... Oct 12 19:03:02 volumio volumio[2654]: info: Loading plugin "appearance"... Oct 12 19:03:03 volumio volumio[2654]: info: Loading plugin "network"... Oct 12 19:03:03 volumio volumio[2654]: info: Refreshing Cached IP Addresses Oct 12 19:03:03 volumio sudo[2712]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 19:03:03 volumio sudo[2712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:03 volumio sudo[2714]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 19:03:03 volumio sudo[2714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:03 volumio volumio[2654]: info: Loading plugin "services"... Oct 12 19:03:03 volumio sudo[2712]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:03 volumio sudo[2714]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:03 volumio volumio[2654]: info: Loading plugin "volumio5onboarding"... Oct 12 19:03:03 volumio volumio[2654]: info: Loading plugin "alsa_controller"... Oct 12 19:03:03 volumio sudo[2721]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 12 19:03:03 volumio sudo[2721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:03 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:03:03 volumio volumio[2654]: info: Loading plugin "wizard"... Oct 12 19:03:03 volumio volumio[2654]: info: Loading plugin "networkfs"... Oct 12 19:03:04 volumio volumio[2654]: info: Cannot mount NAS Music_on_NAS at system boot, trial number 1 ,retrying in 5 seconds Oct 12 19:03:04 volumio volumio[2654]: info: Starting Udev Watcher for removable devices Oct 12 19:03:04 volumio volumio[2654]: info: Ignoring mount for partition: boot Oct 12 19:03:04 volumio volumio[2654]: info: Ignoring mount for partition: volumio Oct 12 19:03:04 volumio volumio[2654]: info: Ignoring mount for partition: volumio_data Oct 12 19:03:04 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 19:03:04 volumio volumio[2654]: info: Loading plugin "volumio_command_line_client"... Oct 12 19:03:04 volumio volumio[2654]: info: Loading plugin "upnp"... Oct 12 19:03:04 volumio volumio[2654]: info: [1791824584052] Starting Upmpd Daemon Oct 12 19:03:04 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 19:03:04 volumio volumio[2654]: info: Loading plugin "my_music"... Oct 12 19:03:04 volumio volumio[2654]: info: Loading plugin "mpd"... Oct 12 19:03:04 volumio volumio[2654]: info: Loading plugin "upnp_browser"... Oct 12 19:03:04 volumio sudo[2721]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:05 volumio volumio[2654]: info: Starting UPNP Browser Oct 12 19:03:05 volumio volumio[2654]: info: Loading plugin "alarm-clock"... Oct 12 19:03:06 volumio volumio[2654]: info: Loading plugin "airplay_emulation"... Oct 12 19:03:06 volumio volumio[2654]: info: Starting Shairport Sync Oct 12 19:03:06 volumio volumio[2654]: info: Loading plugin "last_100"... Oct 12 19:03:06 volumio volumio[2654]: info: Loading plugin "webradio"... Oct 12 19:03:06 volumio volumio[2654]: info: Loading plugin "i2s_dacs"... Oct 12 19:03:06 volumio volumio[2654]: info: I2S DAC not set, start Auto-detection Oct 12 19:03:06 volumio volumio[2654]: info: Loading plugin "volumiodiscovery"... Oct 12 19:03:06 volumio volumio[2654]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 19:03:06 volumio volumio[2654]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:03:06 volumio volumio[2654]: *** WARNING *** For more information see Oct 12 19:03:06 volumio volumio[2654]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 19:03:06 volumio volumio[2654]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:03:06 volumio volumio[2654]: *** WARNING *** For more information see Oct 12 19:03:06 volumio node[2654]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 19:03:06 volumio node[2654]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:03:06 volumio node[2654]: *** WARNING *** For more information see Oct 12 19:03:06 volumio node[2654]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 19:03:06 volumio node[2654]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:03:06 volumio node[2654]: *** WARNING *** For more information see Oct 12 19:03:06 volumio volumio[2654]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 19:03:06 volumio volumio[2654]: info: Discovery: Started advertising with name: Volumio Oct 12 19:03:06 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 19:03:06 volumio volumio[2654]: info: Loading plugin "now_playing"... Oct 12 19:03:07 volumio volumio[2654]: info: Loading plugin "outputs"... Oct 12 19:03:07 volumio volumio[2654]: info: Loading plugin "albumart"... Oct 12 19:03:07 volumio volumio[2654]: info: Plugin example_plugin is not enabled Oct 12 19:03:07 volumio volumio[2654]: info: Loading plugin "inputs"... Oct 12 19:03:07 volumio volumio[2654]: info: Loading plugin "updater_comm"... Oct 12 19:03:07 volumio volumio[2654]: info: Plugin mpdemulation is not enabled Oct 12 19:03:07 volumio volumio[2654]: info: Loading plugin "rest_api"... Oct 12 19:03:07 volumio volumio[2654]: info: Loading plugin "websocket"... Oct 12 19:03:07 volumio volumio[2654]: info: Starting Socket.io Server version 1.7.4 Oct 12 19:03:07 volumio volumio[2654]: info: Loading plugin "soloist_connect"... Oct 12 19:03:08 volumio volumio[2654]: info: Loading i18n strings for locale en Oct 12 19:03:08 volumio volumio[2654]: Updating browse sources language Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::initPlayerControls Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: Express server listening on port 3000 Oct 12 19:03:08 volumio volumio[2654]: [Metrics] WebUI: 6s 847.24ms Oct 12 19:03:08 volumio volumio[2747]: Forking 3 albumart workers Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::resetVolumioState Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::getcurrentVolume Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: Volumio Network Manager: Network status updated: 1 Oct 12 19:03:08 volumio volumio[2654]: info: VolumeController:: Volume=50 Mute =false Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::pushState Oct 12 19:03:08 volumio volumio[2654]: info: CorePlayQueue::getTrack 0 Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioPushState Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::updateTrackBlock Oct 12 19:03:08 volumio volumio[2654]: info: CorePlayQueue::getTrackBlock Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 19:03:08 volumio volumio[2654]: verbose: New Socket.io Connection to 192.168.1.125 from 192.168.1.118 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/154.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 12 19:03:08 volumio volumio[2654]: info: Reloading queue from file Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::setRepeat null single undefined Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::pushState Oct 12 19:03:08 volumio volumio[2654]: info: CorePlayQueue::getTrack 0 Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioPushState Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::setRandom null Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::pushState Oct 12 19:03:08 volumio volumio[2654]: info: CorePlayQueue::getTrack 0 Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioPushState Oct 12 19:03:08 volumio volumio[2654]: info: Setting Device type: Raspberry PI Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioGetState Oct 12 19:03:08 volumio volumio[2654]: info: CorePlayQueue::getTrack 0 Oct 12 19:03:08 volumio volumio[2654]: info: VolumeController:: Volume=50 Mute =false Oct 12 19:03:08 volumio volumio[2654]: info: CoreStateMachine::pushState Oct 12 19:03:08 volumio volumio[2654]: info: CorePlayQueue::getTrack 0 Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioPushState Oct 12 19:03:08 volumio volumio[2654]: info: Listing playlists Oct 12 19:03:08 volumio volumio[2654]: info: Listing playlists Oct 12 19:03:08 volumio volumio[2654]: info: Completed loading Core Plugins Oct 12 19:03:08 volumio volumio[2654]: info: Preparing to generate the ALSA configuration file Oct 12 19:03:08 volumio volumio[2654]: info: Discovery: adding 7bb3d640-4adc-45d0-8e97-2c53fa7f43ee Oct 12 19:03:08 volumio volumio[2654]: info: Discovery: Found device Volumio Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioGetState Oct 12 19:03:08 volumio volumio[2654]: info: CorePlayQueue::getTrack 0 Oct 12 19:03:08 volumio volumio[2654]: info: Asound.conf file unchanged, so no further update is needed Oct 12 19:03:08 volumio volumio[2654]: info: Output device has changed, restarting MPD Oct 12 19:03:08 volumio volumio[2654]: info: Output device has changed, restarting Shairport Sync Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:03:08 volumio sudo[2802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 19:03:08 volumio sudo[2802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:08 volumio sudo[2802]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:08 volumio volumio[2654]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 19:03:08 volumio volumio[2654]: info: ___________ START PLUGINS ___________ Oct 12 19:03:08 volumio sudo[2803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 19:03:08 volumio volumio[2654]: info: ControllerMpd::onStart: Initializing MPD Oct 12 19:03:08 volumio volumio[2654]: info: Creating MPD Configuration file Oct 12 19:03:08 volumio sudo[2803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:08 volumio sudo[2813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 19:03:08 volumio volumio[2654]: info: [1791824588952] CoreMusicLibrary::Adding element Media Servers Oct 12 19:03:08 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:03:08 volumio sudo[2813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:08 volumio sudo[2813]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:08 volumio sudo[2812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 19:03:08 volumio sudo[2812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:08 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 19:03:08 volumio volumio[2654]: info: UPNP Browser: Client initialized successfully Oct 12 19:03:09 volumio sudo[2815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 19:03:09 volumio sudo[2815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:03:09 volumio sudo[2818]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f Oct 12 19:03:09 volumio sudo[2818]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Oct 12 19:03:09 volumio systemd[1]: volumio5-onboarding.service: Start request repeated too quickly. Oct 12 19:03:09 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 12 19:03:09 volumio systemd[1]: Failed to start volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 12 19:03:09 volumio sudo[2812]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:09 volumio volumio[2654]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:03:09 volumio volumio[2654]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 19:03:09 volumio volumio[2654]: info: [1791824589169] CoreMusicLibrary::Adding element Last_100 Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 19:03:09 volumio volumio[2654]: info: [1791824589174] CoreMusicLibrary::Adding element Webradio Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:03:09 volumio volumio[2654]: info: Initializing BBC Radios Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:03:09 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:03:09 volumio volumio[2654]: info: [now-playing] ConfigUpdater: config is up to date. Oct 12 19:03:09 volumio volumio[2654]: info: SoloistConnect: plugin=0.9.0 shim=0.2.9 Oct 12 19:03:09 volumio volumio[2654]: info: SoloistConnect: freshness armed period=24h Oct 12 19:03:09 volumio volumio[2654]: info: Volumio Calling Home Oct 12 19:03:09 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 12 19:03:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 19:03:09 volumio systemd[1]: mpd.service: Consumed 5.761s CPU time. Oct 12 19:03:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 12 19:03:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 19:03:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 19:03:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 19:03:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 19:03:09 volumio volumio-remote-updater[715]: [2026-10-12 19:03:09] [connect] Successful connection Oct 12 19:03:10 volumio sudo[2849]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 19:03:10 volumio sudo[2849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 19:03:10 volumio volumio[2763]: Starting albumart workers Oct 12 19:03:10 volumio sudo[2849]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:10 volumio volumio[2762]: Starting albumart workers Oct 12 19:03:10 volumio volumio[2761]: Starting albumart workers Oct 12 19:03:10 volumio volumio[2654]: info: [now-playing] App is listening on port 4004. Oct 12 19:03:10 volumio volumio[2654]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Oct 12 19:03:10 volumio volumio[2654]: info: Cannot mount NAS Music_on_NAS at system boot, trial number 2 ,retrying in 5 seconds Oct 12 19:03:10 volumio volumio[2654]: info: Discovery: this is already registered, 7bb3d640-4adc-45d0-8e97-2c53fa7f43ee Oct 12 19:03:10 volumio volumio[2654]: info: Discovery: Found device Volumio Oct 12 19:03:10 volumio volumio[2654]: info: CoreCommandRouter::volumioGetState Oct 12 19:03:10 volumio volumio[2654]: info: CorePlayQueue::getTrack 0 Oct 12 19:03:10 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , soloistMeteringWanted Oct 12 19:03:10 volumio volumio[2654]: info: SoloistConnect: writeEnvFile cache_location="disk" cache_size_mb=1024 ceiling=217 -> ramMb=0 CACHE_SIZE=1024 Oct 12 19:03:10 volumio volumio[2654]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:03:10 volumio volumio[2654]: info: MPD Permissions set Oct 12 19:03:10 volumio volumio[2654]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 19:03:10 volumio volumio[2654]: Error: Command failed: /usr/bin/sudo /bin/systemctl start volumio5-onboarding.service Oct 12 19:03:10 volumio volumio[2654]: Job for volumio5-onboarding.service failed because the control process exited with error code. Oct 12 19:03:10 volumio volumio[2654]: See "systemctl status volumio5-onboarding.service" and "journalctl -xeu volumio5-onboarding.service" for details. Oct 12 19:03:10 volumio volumio[2654]: at ChildProcess.exithandler (node:child_process:421:12) Oct 12 19:03:10 volumio volumio[2654]: at ChildProcess.emit (node:events:514:28) Oct 12 19:03:10 volumio volumio[2654]: at maybeClose (node:internal/child_process:1105:16) Oct 12 19:03:10 volumio volumio[2654]: at Socket. (node:internal/child_process:457:11) Oct 12 19:03:10 volumio volumio[2654]: at Socket.emit (node:events:514:28) Oct 12 19:03:10 volumio volumio[2654]: at Pipe. (node:net:337:12) { Oct 12 19:03:10 volumio volumio[2654]: code: 1, Oct 12 19:03:10 volumio volumio[2654]: killed: false, Oct 12 19:03:10 volumio volumio[2654]: signal: null, Oct 12 19:03:10 volumio volumio[2654]: cmd: '/usr/bin/sudo /bin/systemctl start volumio5-onboarding.service', Oct 12 19:03:10 volumio volumio[2654]: stdout: '', Oct 12 19:03:10 volumio volumio[2654]: stderr: 'Job for volumio5-onboarding.service failed because the control process exited with error code.\n' + Oct 12 19:03:10 volumio volumio[2654]: 'See "systemctl status volumio5-onboarding.service" and "journalctl -xeu volumio5-onboarding.service" for details.\n' Oct 12 19:03:10 volumio volumio[2654]: } Oct 12 19:03:10 volumio volumio[2654]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 19:03:10 volumio sudo[2853]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart soloist.service Oct 12 19:03:10 volumio sudo[2853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:10 volumio systemd[1]: Starting soloist.service - Spotify Soloist daemon (Volumio 4 ALSA)... Oct 12 19:03:10 volumio systemd[1]: Started soloist.service - Spotify Soloist daemon (Volumio 4 ALSA). Oct 12 19:03:10 volumio sudo[2853]: pam_unix(sudo:session): session closed for user root Oct 12 19:03:11 volumio launch-soloist.sh[2876]: SoloistConnect: plugin=0.9.0 shim=0.2.9 rev=12387e557e7524f1055bf92257c4b139a0273ba1 userspace=armhf device=plug:volumio tlength_cap=500ms external_volume=true trim=0dB diag=off uname=armv7l Oct 12 19:03:11 volumio launch-soloist.sh[2906]: SoloistConnect: engine_prefs loudness=on crossfade=off stores=2 Oct 12 19:03:11 volumio sudo[2924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 19:02' Oct 12 19:03:11 volumio sudo[2924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:03:11 volumio launch-soloist.sh[2876]: SoloistConnect: interpreter=/data/soloist/sysroot/usr/lib/arm-linux-gnueabihf/ld-linux-armhf.so.3 Oct 12 19:03:11 volumio launch-soloist.sh[2876]: 2026-10-12 19:03:11.775: soloist 1.3.8.105 build 1790942580 (20261002) (g5c3a2053ac) (linux/arm) Oct 12 19:03:11 volumio launch-soloist.sh[2876]: 2026-10-12 19:03:11.777: client expires in 79 days 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"