Aug 26 19:34:39 volumio ntpd[977]: CLOCK: time stepped by 522151.558006 Aug 26 19:34:39 volumio ntpd[977]: CLOCK: time changed from 2026-08-20 to 2026-08-26 Aug 26 19:34:39 volumio ntpd[977]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "network"... Aug 26 19:34:41 volumio volumio[1184]: info: Refreshing Cached IP Addresses Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "services"... Aug 26 19:34:41 volumio sudo[1359]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 19:34:41 volumio sudo[1359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "volumio5onboarding"... Aug 26 19:34:41 volumio sudo[1359]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:41 volumio sudo[1360]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 19:34:41 volumio sudo[1360]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "alsa_controller"... Aug 26 19:34:41 volumio sudo[1369]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 26 19:34:41 volumio sudo[1369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:41 volumio sudo[1360]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:41 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "wizard"... Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "networkfs"... Aug 26 19:34:41 volumio volumio[1184]: info: Starting Udev Watcher for removable devices Aug 26 19:34:41 volumio volumio[1184]: info: Ignoring mount for partition: boot Aug 26 19:34:41 volumio volumio[1184]: info: Ignoring mount for partition: volumio Aug 26 19:34:41 volumio volumio[1184]: info: Ignoring mount for partition: volumio_data Aug 26 19:34:41 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "volumio_command_line_client"... Aug 26 19:34:41 volumio sudo[1393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=qnap_reader,password=qnap_reader,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.10.222/music\\music /mnt/NAS/QNAP Aug 26 19:34:41 volumio volumio[1184]: info: Plugin upnp is not enabled Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "my_music"... Aug 26 19:34:41 volumio sudo[1393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:41 volumio volumio[1184]: info: Loading plugin "mpd"... Aug 26 19:34:41 volumio kernel: netfs: FS-Cache loaded Aug 26 19:34:42 volumio kernel: Key type cifs.spnego registered Aug 26 19:34:42 volumio kernel: Key type cifs.idmap registered Aug 26 19:34:42 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Aug 26 19:34:42 volumio kernel: CIFS: Attempting to mount //192.168.10.222/music/music Aug 26 19:34:42 volumio sudo[1369]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:42 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 26 19:34:42 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Aug 26 19:34:42 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 26 19:34:42 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Aug 26 19:34:42 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 26 19:34:42 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 26 19:34:42 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Aug 26 19:34:42 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Aug 26 19:34:42 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Aug 26 19:34:42 volumio sudo[1393]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:43 volumio volumio[1184]: info: Loading plugin "upnp_browser"... Aug 26 19:34:44 volumio dhcpcd[690]: timed out Aug 26 19:34:44 volumio sh[680]: timed out Aug 26 19:34:44 volumio dhcpcd[690]: dhcpcd exited Aug 26 19:34:44 volumio sh[611]: ifup: failed to bring up eth0 Aug 26 19:34:44 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Aug 26 19:34:44 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Aug 26 19:34:45 volumio volumio[1184]: info: Starting UPNP Browser Aug 26 19:34:45 volumio volumio[1184]: info: Loading plugin "alarm-clock"... Aug 26 19:34:45 volumio volumio[1184]: info: Loading plugin "airplay_emulation"... Aug 26 19:34:45 volumio volumio[1184]: info: Starting Shairport Sync Aug 26 19:34:45 volumio volumio[1184]: info: Loading plugin "last_100"... Aug 26 19:34:45 volumio volumio[1184]: info: Loading plugin "webradio"... Aug 26 19:34:46 volumio volumio[1184]: info: Loading plugin "i2s_dacs"... Aug 26 19:34:46 volumio volumio[1184]: info: Loading plugin "volumiodiscovery"... Aug 26 19:34:46 volumio volumio[1184]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 19:34:46 volumio volumio[1184]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 19:34:46 volumio volumio[1184]: *** WARNING *** For more information see Aug 26 19:34:46 volumio volumio[1184]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 19:34:46 volumio volumio[1184]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 19:34:46 volumio volumio[1184]: *** WARNING *** For more information see Aug 26 19:34:46 volumio node[1184]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 19:34:46 volumio node[1184]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 19:34:46 volumio node[1184]: *** WARNING *** For more information see Aug 26 19:34:46 volumio node[1184]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 19:34:46 volumio node[1184]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 19:34:46 volumio node[1184]: *** WARNING *** For more information see Aug 26 19:34:46 volumio volumio[1184]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 26 19:34:46 volumio volumio[1184]: info: Discovery: Started advertising with name: Volumio Aug 26 19:34:46 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 19:34:46 volumio volumio[1184]: info: Loading plugin "outputs"... Aug 26 19:34:46 volumio volumio[1184]: info: Loading plugin "albumart"... Aug 26 19:34:46 volumio volumio[1184]: info: Plugin example_plugin is not enabled Aug 26 19:34:46 volumio volumio[1184]: info: Loading plugin "inputs"... Aug 26 19:34:46 volumio volumio[1184]: info: Loading plugin "updater_comm"... Aug 26 19:34:47 volumio volumio[1184]: info: Plugin mpdemulation is not enabled Aug 26 19:34:47 volumio volumio[1184]: info: Loading plugin "rest_api"... Aug 26 19:34:47 volumio volumio[1184]: info: Loading plugin "websocket"... Aug 26 19:34:47 volumio volumio[1184]: info: Starting Socket.io Server version 1.7.4 Aug 26 19:34:47 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 26 19:34:47 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:34:47 volumio volumio[1184]: info: Loading i18n strings for locale de Aug 26 19:34:47 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:34:47 volumio volumio[1184]: Updating browse sources language Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 19:34:47 volumio upmpdcli[1457]: Could not open config: /tmp/upmpdcli.conf Aug 26 19:34:47 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 26 19:34:47 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 26 19:34:47 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::initPlayerControls Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 19:34:47 volumio volumio[1184]: Express server listening on port 3000 Aug 26 19:34:47 volumio volumio[1184]: [Metrics] WebUI: 12s 390.49ms Aug 26 19:34:47 volumio volumio[1184]: info: CoreStateMachine::resetVolumioState Aug 26 19:34:47 volumio volumio[1184]: info: CoreStateMachine::getcurrentVolume Aug 26 19:34:47 volumio volumio[1184]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 19:34:47 volumio nmbd[1049]: [2026/08/26 19:34:47.891900, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 26 19:34:47 volumio nmbd[1049]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.10.89 for name WORKGROUP<1d>. Aug 26 19:34:47 volumio nmbd[1049]: This response was from IP 192.168.10.51, reporting an IP address of 192.168.10.51. Aug 26 19:34:47 volumio volumio[1184]: info: Volumio Network Manager: Network status updated: 2 Aug 26 19:34:48 volumio volumio[1184]: verbose: New Socket.io Connection to 192.168.10.89 from 192.168.10.60 UA: Mozilla/5.0 (iPad; CPU OS 12_5_8 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 1 Aug 26 19:34:48 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:34:48 volumio volumio[1184]: info: Reloading queue from file Aug 26 19:34:48 volumio volumio[1447]: Forking 3 albumart workers Aug 26 19:34:48 volumio volumio[1184]: verbose: New Socket.io Connection to 192.168.10.89 from 192.168.10.60 UA: Mozilla/5.0 (iPad; CPU OS 12_5_8 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 2 Aug 26 19:34:48 volumio volumio[1184]: info: VolumeController:: Volume=64 Mute =false Aug 26 19:34:48 volumio volumio[1184]: info: CoreStateMachine::pushState Aug 26 19:34:48 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:34:48 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 19:34:48 volumio volumio[1184]: info: CoreCommandRouter::volumioPushState Aug 26 19:34:48 volumio volumio[1184]: info: CoreStateMachine::updateTrackBlock Aug 26 19:34:48 volumio volumio[1184]: info: CorePlayQueue::getTrackBlock Aug 26 19:34:48 volumio volumio[1184]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 19:34:48 volumio volumio[1184]: info: Setting Device type: Raspberry PI Aug 26 19:34:48 volumio volumio[1184]: verbose: New Socket.io Connection to 192.168.10.89 from 192.168.10.60 UA: Mozilla/5.0 (iPad; CPU OS 12_5_8 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 3 Aug 26 19:34:48 volumio volumio[1184]: info: Completed loading Core Plugins Aug 26 19:34:48 volumio volumio[1184]: info: Preparing to generate the ALSA configuration file Aug 26 19:34:48 volumio volumio[1184]: info: CoreStateMachine::setRepeat null single undefined Aug 26 19:34:48 volumio volumio[1184]: info: CoreStateMachine::pushState Aug 26 19:34:48 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:34:48 volumio volumio[1184]: info: CoreCommandRouter::volumioPushState Aug 26 19:34:48 volumio volumio[1184]: info: CoreStateMachine::setRandom null Aug 26 19:34:48 volumio volumio[1184]: info: CoreStateMachine::pushState Aug 26 19:34:48 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:34:48 volumio volumio[1184]: info: CoreCommandRouter::volumioPushState Aug 26 19:34:49 volumio volumio[1184]: info: Discovery: adding a215eb68-0bc4-48de-bd94-91c5a81c0edf Aug 26 19:34:49 volumio volumio[1184]: info: Discovery: Found device Volumio Aug 26 19:34:49 volumio volumio[1184]: info: CoreCommandRouter::volumioGetState Aug 26 19:34:49 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:34:49 volumio volumio[1184]: info: Discovery: this is already registered, a215eb68-0bc4-48de-bd94-91c5a81c0edf Aug 26 19:34:49 volumio volumio[1184]: info: Discovery: Found device Volumio Aug 26 19:34:49 volumio volumio[1184]: info: CoreCommandRouter::volumioGetState Aug 26 19:34:49 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:34:49 volumio volumio[1184]: info: VolumeController:: Volume=64 Mute =false Aug 26 19:34:49 volumio volumio[1184]: info: CoreStateMachine::pushState Aug 26 19:34:49 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:34:49 volumio volumio[1184]: info: CoreCommandRouter::volumioPushState Aug 26 19:34:49 volumio volumio[1184]: info: Asound.conf file unchanged, so no further update is needed Aug 26 19:34:49 volumio volumio[1184]: info: Output device has changed, restarting MPD Aug 26 19:34:49 volumio volumio[1184]: info: Output device has changed, restarting Shairport Sync Aug 26 19:34:49 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:49 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:34:49 volumio sudo[1507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 19:34:49 volumio sudo[1507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:49 volumio sudo[1507]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:49 volumio sudo[1510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 19:34:49 volumio sudo[1510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:49 volumio volumio[1184]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 19:34:49 volumio volumio[1184]: info: ___________ START PLUGINS ___________ Aug 26 19:34:49 volumio volumio[1184]: info: ControllerMpd::onStart: Initializing MPD Aug 26 19:34:49 volumio sudo[1520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 26 19:34:49 volumio sudo[1520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 19:34:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 19:34:49 volumio volumio[1184]: info: Creating MPD Configuration file Aug 26 19:34:50 volumio sudo[1525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 19:34:50 volumio sudo[1525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:50 volumio sudo[1525]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:50 volumio sudo[1523]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 19:34:50 volumio sudo[1523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 19:34:50 volumio sudo[1529]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 26 19:34:50 volumio sudo[1523]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:50 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 19:34:50 volumio volumio[1184]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 19:34:50 volumio sudo[1528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 19:34:50 volumio sudo[1528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:34:50 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 19:34:50 volumio volumio[1184]: info: [1787765690284] CoreMusicLibrary::Adding element Medienserver Aug 26 19:34:50 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 19:34:50 volumio sudo[1520]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:50 volumio systemd[1]: mpd.service: Deactivated successfully. Aug 26 19:34:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 26 19:34:50 volumio systemd[1]: mpd.socket: Deactivated successfully. Aug 26 19:34:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 26 19:34:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 26 19:34:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 19:34:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 19:34:50 volumio volumio[1184]: info: UPNP Browser: Client initialized successfully Aug 26 19:34:50 volumio sudo[1534]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 19:34:50 volumio sudo[1534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 19:34:50 volumio sudo[1540]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 26 19:34:50 volumio sudo[1534]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:50 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:50 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:34:50 volumio volumio5-onboarding[1532]: time=2026-08-26T19:34:50.998+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 26 19:34:51 volumio volumio[1184]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:34:51 volumio volumio[1184]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 19:34:51 volumio volumio[1184]: info: [1787765691327] CoreMusicLibrary::Adding element Last_100 Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 19:34:51 volumio volumio[1184]: info: [1787765691380] CoreMusicLibrary::Adding element Webradio Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 19:34:51 volumio volumio[1184]: info: Initializing BBC Radios Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 19:34:51 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:34:51 volumio volumio[1184]: info: Volumio Calling Home Aug 26 19:34:54 volumio volumio-remote-updater[775]: [2026-08-26 19:34:54] [connect] Successful connection Aug 26 19:34:54 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 26 19:34:56 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 26 19:34:56 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 26 19:34:56 volumio systemd[1]: setdatetime-helper.service: Consumed 1.150s CPU time. Aug 26 19:34:57 volumio volumio[1184]: info: MPD Permissions set Aug 26 19:34:57 volumio volumio[1184]: info: MPD Permissions set Aug 26 19:34:58 volumio volumio[1184]: 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: 4 Aug 26 19:34:58 volumio volumio[1184]: info: Volumio called home Aug 26 19:34:59 volumio mpd[1541]: 2026-08-26T19:34:59 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 19:34:59 volumio volumio[1184]: 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: 4 Aug 26 19:34:59 volumio volumio[1184]: info: Received Get System Info Aug 26 19:34:59 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 19:34:59 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 19:34:59 volumio volumio[1184]: info: Discovery: Getting this device information Aug 26 19:34:59 volumio volumio[1184]: info: CoreCommandRouter::volumioGetState Aug 26 19:34:59 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:34:59 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 19:34:59 volumio volumio5-onboarding[1532]: time=2026-08-26T19:34:59.311+02:00 level=INFO msg="system info for c4d6da523d9ddd4927104cf732d10344" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 26 19:34:59 volumio volumio5-onboarding[1532]: time=2026-08-26T19:34:59.325+02:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 26 19:34:59 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 26 19:34:59 volumio sudo[1510]: pam_unix(sudo:session): session closed for user root Aug 26 19:34:59 volumio sudo[1528]: pam_unix(sudo:session): session closed for user root Aug 26 19:35:00 volumio volumio[1480]: Starting albumart workers Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:01 volumio volumio[1184]: info: Received Get System Info Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 19:35:01 volumio volumio[1184]: info: Discovery: Getting this device information Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::volumioGetState Aug 26 19:35:01 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:35:01 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 19:35:01 volumio volumio[1479]: Starting albumart workers Aug 26 19:35:01 volumio volumio[1478]: Starting albumart workers Aug 26 19:35:01 volumio volumio[1184]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 26 19:35:02 volumio volumio[1184]: info: Completed starting Core Plugins Aug 26 19:35:02 volumio volumio[1184]: info: ------------------------------------------- Aug 26 19:35:02 volumio volumio[1184]: info: ----- MyVolumio plugins startup ---- Aug 26 19:35:02 volumio volumio[1184]: info: ------------------------------------------- Aug 26 19:35:02 volumio volumio[1184]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 19:35:02 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Aug 26 19:35:02 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:35:02 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:35:02 volumio volumio[1184]: verbose: New Socket.io Connection to 192.168.10.89 from 192.168.10.60 UA: Mozilla/5.0 (iPad; CPU OS 12_5_8 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 6 Aug 26 19:35:02 volumio upmpdcli[1642]: Could not open config: /tmp/upmpdcli.conf Aug 26 19:35:02 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 26 19:35:02 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 26 19:35:03 volumio volumio[1184]: info: MPD running with PID1541 Aug 26 19:35:03 volumio volumio[1184]: ,establishing connection Aug 26 19:35:03 volumio volumio[1184]: error: MPD error: The expression evaluated to a falsy value: Aug 26 19:35:03 volumio volumio[1184]: assert.ok(self.idling) Aug 26 19:35:03 volumio volumio[1184]: error: The expression evaluated to a falsy value: Aug 26 19:35:03 volumio volumio[1184]: assert.ok(self.idling) Aug 26 19:35:03 volumio volumio[1184]: error: MPD error: The expression evaluated to a falsy value: Aug 26 19:35:03 volumio volumio[1184]: assert.ok(self.idling) Aug 26 19:35:04 volumio volumio[1184]: error: The expression evaluated to a falsy value: Aug 26 19:35:04 volumio volumio[1184]: assert.ok(self.idling) Aug 26 19:35:04 volumio volumio[1184]: verbose: New Socket.io Connection to 192.168.10.89 from 192.168.10.60 UA: Mozilla/5.0 (iPad; CPU OS 12_5_8 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 7 Aug 26 19:35:04 volumio volumio[1184]: info: Starting Shairport Sync Aug 26 19:35:04 volumio volumio[1184]: info: Starting Shairport Sync Aug 26 19:35:04 volumio volumio[1184]: info: Starting Shairport Sync Aug 26 19:35:04 volumio sudo[1646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 19:35:04 volumio sudo[1646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:35:04 volumio sudo[1644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 19:35:04 volumio sudo[1644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:35:04 volumio sudo[1648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 19:35:04 volumio sudo[1648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 19:35:04 volumio volumio[1184]: verbose: New Socket.io Connection to 192.168.10.89 from 192.168.10.60 UA: Mozilla/5.0 (iPad; CPU OS 12_5_8 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 8 Aug 26 19:35:04 volumio volumio[1184]: error: updateQueue error: null Aug 26 19:35:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 19:35:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 19:35:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 19:35:04 volumio systemd[1]: shairport-sync.service: Consumed 1.226s CPU time. Aug 26 19:35:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 19:35:04 volumio sudo[1648]: pam_unix(sudo:session): session closed for user root Aug 26 19:35:04 volumio sudo[1646]: pam_unix(sudo:session): session closed for user root Aug 26 19:35:04 volumio sudo[1644]: pam_unix(sudo:session): session closed for user root Aug 26 19:35:05 volumio volumio[1184]: info: Shairport-Sync Started Aug 26 19:35:05 volumio volumio[1184]: Error adding Membership: Error: addMembership EINVAL Aug 26 19:35:05 volumio volumio[1184]: info: Shairport-Sync Started Aug 26 19:35:05 volumio volumio[1184]: info: Shairport-Sync Started Aug 26 19:35:05 volumio volumio[1184]: info: CoreCommandRouter::volumioGetState Aug 26 19:35:05 volumio volumio[1184]: info: CorePlayQueue::getTrack 0 Aug 26 19:35:09 volumio volumio[1184]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 19:35:09 volumio volumio-remote-updater[775]: [2026-08-26 19:35:09] [connect] Successful connection Aug 26 19:35:17 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Aug 26 19:35:17 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:35:18 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:35:18 volumio upmpdcli[1699]: Could not open config: /tmp/upmpdcli.conf Aug 26 19:35:18 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 26 19:35:18 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 26 19:35:24 volumio volumio-remote-updater[775]: [2026-08-26 19:35:24] [connect] Successful connection Aug 26 19:35:29 volumio volumio5-onboarding[1532]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Aug 26 19:35:29 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 19:35:29 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 19:35:29 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 26 19:35:29 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 19:35:29 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 19:35:29 volumio volumio5-onboarding[1714]: time=2026-08-26T19:35:29.731+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 26 19:35:33 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5. Aug 26 19:35:33 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:35:33 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 19:35:33 volumio upmpdcli[1735]: Could not open config: /tmp/upmpdcli.conf Aug 26 19:35:33 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 26 19:35:33 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 19:35:34 volumio volumio[1184]: error: MyVolumio Plugin failed to start in a timely fashion Aug 26 19:35:34 volumio volumio[1184]: [Metrics] CommandRouter: 57s 817.96ms Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::volumiosetStartupVolume Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::Close All Modals sent Aug 26 19:35:34 volumio volumio[1184]: info: CoreCommandRouter::Close All Modals sent Aug 26 19:35:35 volumio volumio[1184]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 19:35:35 volumio volumio[1184]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Aug 26 19:35:35 volumio volumio[1184]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Aug 26 19:35:35 volumio volumio[1184]: at new NodeError (node:internal/errors:405:5) Aug 26 19:35:35 volumio volumio[1184]: at assert (node:internal/assert:14:11) Aug 26 19:35:35 volumio volumio[1184]: at internalConnectMultiple (node:net:1118:3) Aug 26 19:35:35 volumio volumio[1184]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Aug 26 19:35:35 volumio volumio[1184]: at listOnTimeout (node:internal/timers:575:11) Aug 26 19:35:35 volumio volumio[1184]: at process.processTimers (node:internal/timers:514:7) { Aug 26 19:35:35 volumio volumio[1184]: code: 'ERR_INTERNAL_ASSERTION' Aug 26 19:35:35 volumio volumio[1184]: } Aug 26 19:35:35 volumio volumio[1184]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 19:35:39 volumio volumio-remote-updater[775]: [2026-08-26 19:35:39] [connect] Successful connection Aug 26 19:35:39 volumio volumio5-onboarding[1714]: 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:40206->127.0.0.1:3000: i/o timeout Aug 26 19:35:39 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 19:35:39 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 19:35:39 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Aug 26 19:35:39 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 19:35:40 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 19:35:40 volumio volumio5-onboarding[1754]: time=2026-08-26T19:35:40.207+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 26 19:35:40 volumio sudo[1763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 19:34' Aug 26 19:35:40 volumio sudo[1763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="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"