Apr 15 11:02:01 volumio volumio[1318]: info: MYVOLUMIO Environment detected
Apr 15 11:02:01 volumio volumio[1318]: info: Plugin folders cleanup
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning into folder /volumio/app/plugins/
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning category audio_interface
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning category miscellanea
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning category music_service
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning category plugins.json
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning category system_controller
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning category user_interface
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning into folder /data/plugins/
Apr 15 11:02:01 volumio volumio[1318]: info: Scanning category music_service
Apr 15 11:02:01 volumio volumio[1318]: info: Plugin folders cleanup completed
Apr 15 11:02:01 volumio volumio[1318]: info: -------------------------------------------
Apr 15 11:02:01 volumio volumio[1318]: info: ----- Core plugins startup ----
Apr 15 11:02:01 volumio volumio[1318]: info: -------------------------------------------
Apr 15 11:02:01 volumio volumio[1318]: info: Loading plugins from folder /volumio/app/plugins/
Apr 15 11:02:01 volumio volumio[1318]: info: Adding plugin upnp to MyMusic Plugins
Apr 15 11:02:01 volumio volumio[1318]: info: Adding plugin airplay_emulation to MyMusic Plugins
Apr 15 11:02:01 volumio volumio[1318]: info: Adding plugin upnp_browser to MyMusic Plugins
Apr 15 11:02:01 volumio volumio[1318]: info: Loading plugins from folder /data/plugins/
Apr 15 11:02:02 volumio volumio[1318]: info: Loading plugin "system"...
Apr 15 11:02:02 volumio volumio[1318]: info: Loading plugin "appearance"...
Apr 15 11:02:04 volumio volumio-remote-updater[720]: [2026-04-15 11:02:04] [connect] Successful connection
Apr 15 11:02:04 volumio volumio[1318]: info: Loading plugin "network"...
Apr 15 11:02:04 volumio volumio[1318]: info: Refreshing Cached IP Addresses
Apr 15 11:02:04 volumio sudo[1357]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 15 11:02:04 volumio sudo[1357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:04 volumio sudo[1357]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:04 volumio volumio[1318]: info: Loading plugin "services"...
Apr 15 11:02:04 volumio volumio[1318]: info: Loading plugin "volumio5onboarding"...
Apr 15 11:02:04 volumio sudo[1364]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Apr 15 11:02:04 volumio sudo[1364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:05 volumio sudo[1359]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 15 11:02:05 volumio sudo[1359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:05 volumio volumio[1318]: info: Loading plugin "alsa_controller"...
Apr 15 11:02:05 volumio sudo[1359]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:05 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 15 11:02:05 volumio volumio[1318]: info: Loading plugin "wizard"...
Apr 15 11:02:05 volumio volumio[1318]: info: Loading plugin "networkfs"...
Apr 15 11:02:05 volumio volumio[1318]: info: Starting Udev Watcher for removable devices
Apr 15 11:02:05 volumio volumio[1318]: info: Ignoring mount for partition: boot
Apr 15 11:02:05 volumio volumio[1318]: info: Ignoring mount for partition: volumio
Apr 15 11:02:05 volumio volumio[1318]: info: Ignoring mount for partition: volumio_data
Apr 15 11:02:05 volumio sudo[1388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=monchi,password=reik0san999,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.100.5/music /mnt/NAS/wanas
Apr 15 11:02:05 volumio sudo[1388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:05 volumio volumio[1318]: info: Mounting Device Music
Apr 15 11:02:05 volumio sudo[1399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Music -o noatime,dmask=0000,fmask=0000,iocharset=utf8
Apr 15 11:02:05 volumio sudo[1399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:05 volumio kernel: netfs: FS-Cache loaded
Apr 15 11:02:05 volumio kernel: Key type cifs.spnego registered
Apr 15 11:02:05 volumio kernel: Key type cifs.idmap registered
Apr 15 11:02:05 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.
Apr 15 11:02:05 volumio kernel: CIFS: Attempting to mount //192.168.100.5/music
Apr 15 11:02:06 volumio sudo[1388]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:06 volumio ntfs-3g[1434]: Version 2022.10.3 integrated FUSE 28
Apr 15 11:02:06 volumio ntfs-3g[1434]: Mounted /dev/sda1 (Read-Write, label "Music", NTFS 3.1)
Apr 15 11:02:06 volumio ntfs-3g[1434]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8
Apr 15 11:02:06 volumio ntfs-3g[1434]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096
Apr 15 11:02:06 volumio ntfs-3g[1434]: Global ownership and permissions enforced, configuration type 7
Apr 15 11:02:06 volumio sudo[1399]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:06 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 15 11:02:06 volumio volumio[1318]: info: Loading plugin "volumio_command_line_client"...
Apr 15 11:02:06 volumio volumio[1318]: info: Loading plugin "upnp"...
Apr 15 11:02:06 volumio volumio[1318]: info: [1776218526758] Starting Upmpd Daemon
Apr 15 11:02:06 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 15 11:02:06 volumio volumio[1318]: info: Loading plugin "my_music"...
Apr 15 11:02:06 volumio volumio[1318]: info: Loading plugin "mpd"...
Apr 15 11:02:07 volumio volumio[1318]: info: Loading plugin "upnp_browser"...
Apr 15 11:02:07 volumio sudo[1364]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:07 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully.
Apr 15 11:02:09 volumio volumio[1318]: info: Starting UPNP Browser
Apr 15 11:02:09 volumio volumio[1318]: info: Loading plugin "alarm-clock"...
Apr 15 11:02:10 volumio volumio[1318]: info: Loading plugin "airplay_emulation"...
Apr 15 11:02:10 volumio volumio[1318]: info: Starting Shairport Sync
Apr 15 11:02:10 volumio volumio[1318]: info: Loading plugin "last_100"...
Apr 15 11:02:10 volumio volumio[1318]: info: Loading plugin "webradio"...
Apr 15 11:02:10 volumio volumio[1318]: info: Loading plugin "i2s_dacs"...
Apr 15 11:02:10 volumio volumio[1318]: info: Loading plugin "volumiodiscovery"...
Apr 15 11:02:10 volumio volumio[1318]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 15 11:02:10 volumio volumio[1318]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 15 11:02:10 volumio volumio[1318]: *** WARNING *** For more information see
Apr 15 11:02:10 volumio volumio[1318]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 15 11:02:10 volumio node[1318]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 15 11:02:10 volumio volumio[1318]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 15 11:02:10 volumio volumio[1318]: *** WARNING *** For more information see
Apr 15 11:02:10 volumio node[1318]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 15 11:02:10 volumio node[1318]: *** WARNING *** For more information see
Apr 15 11:02:10 volumio node[1318]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 15 11:02:10 volumio node[1318]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 15 11:02:10 volumio node[1318]: *** WARNING *** For more information see
Apr 15 11:02:10 volumio volumio[1318]: info: Applying required configuration parameters for plugin volumiodiscovery
Apr 15 11:02:10 volumio volumio[1318]: info: Discovery: Started advertising with name: Volumio
Apr 15 11:02:10 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 15 11:02:10 volumio volumio[1318]: info: Loading plugin "spop"...
Apr 15 11:02:12 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2.
Apr 15 11:02:12 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Apr 15 11:02:12 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Apr 15 11:02:13 volumio upmpdcli[1438]: Could not open config: /tmp/upmpdcli.conf
Apr 15 11:02:13 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Apr 15 11:02:13 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Apr 15 11:02:13 volumio volumio[1318]: info: Loading plugin "outputs"...
Apr 15 11:02:13 volumio volumio[1318]: info: Loading plugin "albumart"...
Apr 15 11:02:13 volumio volumio[1318]: info: Plugin example_plugin is not enabled
Apr 15 11:02:13 volumio volumio[1318]: info: Loading plugin "inputs"...
Apr 15 11:02:13 volumio volumio[1318]: info: Loading plugin "updater_comm"...
Apr 15 11:02:14 volumio volumio[1318]: info: Plugin mpdemulation is not enabled
Apr 15 11:02:14 volumio volumio[1318]: info: Loading plugin "rest_api"...
Apr 15 11:02:14 volumio volumio[1318]: info: Loading plugin "websocket"...
Apr 15 11:02:14 volumio volumio[1318]: info: Starting Socket.io Server version 1.7.4
Apr 15 11:02:14 volumio volumio[1318]: info: Loading i18n strings for locale ja
Apr 15 11:02:14 volumio volumio[1318]: Updating browse sources language
Apr 15 11:02:14 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 15 11:02:14 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::initPlayerControls
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 15 11:02:15 volumio volumio[1318]: Express server listening on port 3000
Apr 15 11:02:15 volumio volumio[1318]: [Metrics] WebUI: 16s 514.28ms
Apr 15 11:02:15 volumio volumio[1318]: info: CoreStateMachine::resetVolumioState
Apr 15 11:02:15 volumio volumio[1318]: info: CoreStateMachine::getcurrentVolume
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::volumioRetrievevolume
Apr 15 11:02:15 volumio volumio[1318]: info: CoreStateMachine::pushState
Apr 15 11:02:15 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 15 11:02:15 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Apr 15 11:02:15 volumio volumio[1318]: info: Volumio Network Manager: Network status updated: 1
Apr 15 11:02:15 volumio volumio[1439]: Forking 3 albumart workers
Apr 15 11:02:16 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:16 volumio volumio[1318]: info: Reloading queue from file
Apr 15 11:02:16 volumio volumio[1318]: info: CoreStateMachine::setRepeat true single undefined
Apr 15 11:02:16 volumio volumio[1318]: info: CoreStateMachine::pushState
Apr 15 11:02:16 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Apr 15 11:02:16 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 15 11:02:16 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Apr 15 11:02:16 volumio volumio[1318]: info: CoreStateMachine::setRandom null
Apr 15 11:02:16 volumio volumio[1318]: info: CoreStateMachine::pushState
Apr 15 11:02:16 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Apr 15 11:02:16 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Apr 15 11:02:16 volumio volumio[1318]: info: Setting Device type: Raspberry PI
Apr 15 11:02:16 volumio volumio[1318]: info: Completed loading Core Plugins
Apr 15 11:02:16 volumio volumio[1318]: info: Preparing to generate the ALSA configuration file
Apr 15 11:02:16 volumio volumio[1318]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb
Apr 15 11:02:16 volumio volumio[1318]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112
Apr 15 11:02:17 volumio volumio[1318]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI
Apr 15 11:02:17 volumio volumio[1318]: info: Discovery: adding fcdc47de-7551-4f35-9fc3-d2a348081812
Apr 15 11:02:17 volumio volumio[1318]: info: Discovery: Found device Volumio
Apr 15 11:02:17 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState
Apr 15 11:02:17 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Apr 15 11:02:17 volumio sudo[1508]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 15 11:02:17 volumio sudo[1508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:17 volumio volumio[1318]: info: Discovery: this is already registered, fcdc47de-7551-4f35-9fc3-d2a348081812
Apr 15 11:02:17 volumio volumio[1318]: info: Discovery: Found device Volumio
Apr 15 11:02:17 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState
Apr 15 11:02:17 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Apr 15 11:02:17 volumio sudo[1508]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:17 volumio sudo[1510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 15 11:02:17 volumio sudo[1510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:17 volumio sudo[1510]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:17 volumio volumio[1318]: info: Asound.conf file unchanged, so no further update is needed
Apr 15 11:02:17 volumio volumio[1318]: info: Output device has changed, restarting MPD
Apr 15 11:02:17 volumio volumio[1318]: info: Output device has changed, restarting Shairport Sync
Apr 15 11:02:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:17 volumio sudo[1514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 15 11:02:17 volumio sudo[1514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:18 volumio sudo[1514]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:18 volumio sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 15 11:02:18 volumio sudo[1516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:18 volumio volumio[1318]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 15 11:02:18 volumio volumio[1318]: info: ___________ START PLUGINS ___________
Apr 15 11:02:18 volumio volumio[1318]: info: ControllerMpd::onStart: Initializing MPD
Apr 15 11:02:18 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Apr 15 11:02:18 volumio volumio[1318]: info: Creating MPD Configuration file
Apr 15 11:02:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 15 11:02:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 15 11:02:18 volumio sudo[1531]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 15 11:02:18 volumio sudo[1531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 15 11:02:18 volumio sudo[1544]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
Apr 15 11:02:18 volumio sudo[1531]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:18 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 15 11:02:18 volumio volumio[1318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 15 11:02:18 volumio volumio[1318]: info: [1776218538942] CoreMusicLibrary::Adding element DLNAサーバー
Apr 15 11:02:18 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 15 11:02:19 volumio sudo[1525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service
Apr 15 11:02:19 volumio sudo[1545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 15 11:02:19 volumio sudo[1525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:19 volumio volumio[1318]: info: UPNP Browser: Client initialized successfully
Apr 15 11:02:19 volumio sudo[1541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 15 11:02:19 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:19 volumio sudo[1545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:19 volumio volumio-remote-updater[720]: [2026-04-15 11:02:19] [connect] Successful connection
Apr 15 11:02:19 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:19 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Apr 15 11:02:19 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:19 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:19 volumio sudo[1525]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:19 volumio systemd[1]: mpd.service: Deactivated successfully.
Apr 15 11:02:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 15 11:02:19 volumio systemd[1]: mpd.socket: Deactivated successfully.
Apr 15 11:02:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 15 11:02:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 15 11:02:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 15 11:02:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 15 11:02:19 volumio volumio[1318]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 15 11:02:19 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:19 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:20 volumio sudo[1562]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 15 11:02:20 volumio sudo[1562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 15 11:02:20 volumio sudo[1566]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
Apr 15 11:02:20 volumio sudo[1562]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:20 volumio volumio[1318]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 15 11:02:20 volumio volumio[1318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 15 11:02:20 volumio volumio[1318]: info: [1776218540340] CoreMusicLibrary::Adding element Last_100
Apr 15 11:02:20 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 15 11:02:20 volumio volumio5-onboarding[1552]: time=2026-04-15T11:02:20.364+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
Apr 15 11:02:20 volumio volumio[1318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 15 11:02:20 volumio volumio[1318]: info: [1776218540457] CoreMusicLibrary::Adding element Webradio
Apr 15 11:02:20 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 15 11:02:20 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 15 11:02:20 volumio volumio[1318]: info: Initializing BBC Radios
Apr 15 11:02:21 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Apr 15 11:02:21 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Apr 15 11:02:21 volumio systemd[1]: setdatetime-helper.service: Consumed 1.312s CPU time.
Apr 15 11:02:21 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 15 11:02:21 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:22 volumio volumio[1318]: info: Creating Spotify config file
Apr 15 11:02:22 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:26 volumio volumio[1318]: info: Volumio Calling Home
Apr 15 11:02:28 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3.
Apr 15 11:02:28 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Apr 15 11:02:28 volumio mpd[1567]: 2026-04-15T11:02:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 15 11:02:28 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Apr 15 11:02:28 volumio upmpdcli[1611]: :3:../libupnpp/upnpplib.cxx:273::LibUPnP: Using IPV4 192.168.100.70 port 49152 IPV6 port 49152
Apr 15 11:02:28 volumio upmpdcli[1611]: :3:../src/mediaserver/cdplugins/plgwithslave.cxx:248::PlgWithSlave: starting streaming proxy on port 49149
Apr 15 11:02:28 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Apr 15 11:02:28 volumio sudo[1545]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:28 volumio sudo[1516]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:28 volumio upmpdcli[1625]: writing RSA key
Apr 15 11:02:30 volumio volumio[1471]: Starting albumart workers
Apr 15 11:02:30 volumio volumio5-onboarding[1552]: 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:58534->127.0.0.1:3000: i/o timeout
Apr 15 11:02:30 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Apr 15 11:02:30 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Apr 15 11:02:30 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1.
Apr 15 11:02:30 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Apr 15 11:02:30 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Apr 15 11:02:30 volumio volumio5-onboarding[1629]: time=2026-04-15T11:02:30.783+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
Apr 15 11:02:31 volumio volumio[1318]: info: MPD Permissions set
Apr 15 11:02:31 volumio volumio[1318]: info: Completed starting Core Plugins
Apr 15 11:02:31 volumio volumio[1318]: info: -------------------------------------------
Apr 15 11:02:31 volumio volumio[1318]: info: ----- MyVolumio plugins startup ----
Apr 15 11:02:31 volumio volumio[1318]: info: -------------------------------------------
Apr 15 11:02:31 volumio volumio[1318]: info: [MyVolumio PluginManager] Fetching plans data....
Apr 15 11:02:31 volumio volumio[1318]: info: MPD Permissions set
Apr 15 11:02:31 volumio volumio[1318]: info: Volumio called home
Apr 15 11:02:31 volumio volumio[1318]: info: Spotify config file written
Apr 15 11:02:31 volumio sudo[1642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Apr 15 11:02:31 volumio sudo[1642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:32 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 15 11:02:32 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Apr 15 11:02:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 15 11:02:32 volumio go-librespot[1645]: go-librespot daemon starting...
Apr 15 11:02:32 volumio sudo[1642]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:32 volumio volumio[1469]: Starting albumart workers
Apr 15 11:02:32 volumio go-librespot[1646]: time="2026-04-15T11:02:32+09:00" level=info msg="running go-librespot 0.7.1"
Apr 15 11:02:32 volumio go-librespot[1646]: time="2026-04-15T11:02:32+09:00" level=debug msg="app state loaded"
Apr 15 11:02:32 volumio volumio[1472]: Starting albumart workers
Apr 15 11:02:32 volumio go-librespot[1646]: time="2026-04-15T11:02:32+09:00" level=info msg="api server listening on 127.0.0.1:9879"
Apr 15 11:02:33 volumio volumio[1318]: error: MPD error: The expression evaluated to a falsy value:
Apr 15 11:02:33 volumio volumio[1318]: assert.ok(self.idling)
Apr 15 11:02:33 volumio volumio[1318]: error: The expression evaluated to a falsy value:
Apr 15 11:02:33 volumio volumio[1318]: assert.ok(self.idling)
Apr 15 11:02:33 volumio volumio[1318]: info: MPD running with PID1567
Apr 15 11:02:33 volumio volumio[1318]: ,establishing connection
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=info msg="zeroconf server listening on port 45081"
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration"
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="obtained new client token: AACEx4U+EPBl//0yEsxLqar62nP6xW9EYG8t34vemtB1fUyx12nQTifoVkbNdps8NggOvUHXgXQ4t9aacMrslbbMp35hhS07udQ5LXUYfCa5D1Mad9vbvJ9VgGuqcERIL9ZsoeBs4hbIs3ylbvBC05GXVTdAvkPlk+MZQcmQmkEr6ngQmYZU1z3gg0OQVFu7MIavgCP6gV/P+GjpJswNHcD+s0pDHUIaDkR+WLKaF4vwYKouRHtWiXdzeQ=="
Apr 15 11:02:33 volumio sudo[1657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Apr 15 11:02:33 volumio sudo[1657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="completed keyexchange"
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="completed challenge"
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: No need to fix Spotify hosts
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=info msg="authenticated AP" username="h4*********************l6"
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=info msg="authenticated Login5" username="h4*********************l6"
Apr 15 11:02:33 volumio go-librespot[1646]: time="2026-04-15T11:02:33+09:00" level=debug msg="initializing zeroconf session" username="h4*********************l6"
Apr 15 11:02:33 volumio sudo[1657]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="dealer connection opened"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=trace msg="starting accesspoint recv loop"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=trace msg="received accesspoint ping"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=trace msg="starting dealer recv loop"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="received connection id: NzVkMmM3YWItOTkw...MTAyRjAyQ0U5Mw=="
Apr 15 11:02:34 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:34 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=trace msg="received accesspoint pong ack"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="put connect state because NEW_DEVICE"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="update volume requested to 65535/65535"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=debug msg="put connect state because VOLUME_CHANGED"
Apr 15 11:02:34 volumio go-librespot[1646]: time="2026-04-15T11:02:34+09:00" level=trace msg="emitting websocket event: volume"
Apr 15 11:02:34 volumio volumio[1318]: error: updateQueue error: null
Apr 15 11:02:34 volumio volumio-remote-updater[720]: [2026-04-15 11:02:34] [connect] Successful connection
Apr 15 11:02:35 volumio volumio[1318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1
Apr 15 11:02:36 volumio volumio[1318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2
Apr 15 11:02:36 volumio volumio[1318]: info: Upmpdcli Daemon Started
Apr 15 11:02:36 volumio volumio[1318]: error: updateQueue error: null
Apr 15 11:02:37 volumio volumio[1318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2
Apr 15 11:02:37 volumio volumio[1318]: info: Received Get System Info
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 15 11:02:37 volumio volumio[1318]: info: Discovery: Getting this device information
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState
Apr 15 11:02:37 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 15 11:02:37 volumio volumio5-onboarding[1629]: time=2026-04-15T11:02:37.146+09:00 level=INFO msg="system info for 1a2fac9e2268945674d9fe3f22a42046" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119
Apr 15 11:02:37 volumio volumio5-onboarding[1629]: time=2026-04-15T11:02:37.161+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Apr 15 11:02:37 volumio volumio-remote-updater[720]: [2026-04-15 11:02:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776218554 101
Apr 15 11:02:37 volumio volumio[1318]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3
Apr 15 11:02:37 volumio volumio[1318]: info: Starting Shairport Sync
Apr 15 11:02:37 volumio volumio[1318]: info: Starting Shairport Sync
Apr 15 11:02:37 volumio volumio[1318]: info: Starting Shairport Sync
Apr 15 11:02:37 volumio volumio[1318]: info: Received Get System Info
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 15 11:02:37 volumio volumio[1318]: info: Discovery: Getting this device information
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState
Apr 15 11:02:37 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Apr 15 11:02:37 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 15 11:02:37 volumio sudo[1694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 15 11:02:37 volumio sudo[1694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:37 volumio sudo[1692]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 15 11:02:37 volumio sudo[1692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:38 volumio sudo[1696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 15 11:02:38 volumio sudo[1696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 15 11:02:38 volumio volumio[1318]: info: New Spotify access tokenBQDEQDPJJp...
Apr 15 11:02:38 volumio volumio[1318]: info: Spotify credentials grant success - running version from March 24, 2019
Apr 15 11:02:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 15 11:02:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 15 11:02:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 15 11:02:38 volumio systemd[1]: shairport-sync.service: Consumed 2.235s CPU time.
Apr 15 11:02:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 15 11:02:38 volumio sudo[1692]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 15 11:02:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 15 11:02:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 15 11:02:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 15 11:02:38 volumio sudo[1696]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:38 volumio sudo[1694]: pam_unix(sudo:session): session closed for user root
Apr 15 11:02:40 volumio volumio-remote-updater[720]: Test mode disabled
Apr 15 11:02:40 volumio volumio-remote-updater[720]: Alpha mode disabled
Apr 15 11:02:40 volumio volumio-remote-updater[720]: Alpha legacy test mode disabled
Apr 15 11:02:40 volumio volumio[1318]: info: go-librespot daemon successfully initialized
Apr 15 11:02:45 volumio volumio[1318]: info: Shairport-Sync Started
Apr 15 11:02:45 volumio volumio[1318]: Error adding Membership: Error: addMembership EINVAL
Apr 15 11:02:46 volumio volumio[1318]: info: Shairport-Sync Started
Apr 15 11:02:46 volumio volumio[1318]: info: Shairport-Sync Started
Apr 15 11:02:46 volumio volumio[1318]: info: Initializing connection to go-librespot Websocket
Apr 15 11:02:56 volumio volumio[1318]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Apr 15 11:02:56 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Apr 15 11:02:56 volumio volumio[1318]: error: MyVolumio Plugin failed to start in a timely fashion
Apr 15 11:02:56 volumio volumio[1318]: [Metrics] CommandRouter: 56s 898.50ms
Apr 15 11:02:56 volumio volumio[1318]: info: CoreCommandRouter::volumiosetStartupVolume
Apr 15 11:02:56 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 15 11:02:56 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:56 volumio volumio[1318]: info: CoreCommandRouter::Close All Modals sent
Apr 15 11:02:57 volumio volumio[1318]: info: CoreCommandRouter::Close All Modals sent
Apr 15 11:02:57 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 15 11:02:57 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 15 11:02:57 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 15 11:02:57 volumio volumio[1318]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 15 11:02:57 volumio volumio[1318]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals.
Apr 15 11:02:57 volumio volumio[1318]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues
Apr 15 11:02:57 volumio volumio[1318]: at new NodeError (node:internal/errors:405:5)
Apr 15 11:02:57 volumio volumio[1318]: at assert (node:internal/assert:14:11)
Apr 15 11:02:57 volumio volumio[1318]: at internalConnectMultiple (node:net:1118:3)
Apr 15 11:02:57 volumio volumio[1318]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3)
Apr 15 11:02:57 volumio volumio[1318]: at listOnTimeout (node:internal/timers:575:11)
Apr 15 11:02:57 volumio volumio[1318]: at process.processTimers (node:internal/timers:514:7) {
Apr 15 11:02:57 volumio volumio[1318]: code: 'ERR_INTERNAL_ASSERTION'
Apr 15 11:02:57 volumio volumio[1318]: }
Apr 15 11:02:57 volumio volumio[1318]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 15 11:03:04 volumio go-librespot[1646]: time="2026-04-15T11:03:04+09:00" level=trace msg="sent dealer ping"
Apr 15 11:03:04 volumio go-librespot[1646]: time="2026-04-15T11:03:04+09:00" level=trace msg="received dealer pong"
Apr 15 11:03:04 volumio sudo[1776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 11:02'
Apr 15 11:03:04 volumio sudo[1776]: 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"