-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sat 2026-04-11 17:49:17 CEST. -- Apr 11 17:48:01 volumio volumio[1012]: info: Loading plugin "network"... Apr 11 17:48:01 volumio volumio[1012]: info: Refreshing Cached IP Addresses Apr 11 17:48:01 volumio sudo[1078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 17:48:01 volumio sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:01 volumio sudo[1080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 17:48:02 volumio sudo[1080]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:02 volumio sudo[1078]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:02 volumio volumio[1012]: info: Loading plugin "services"... Apr 11 17:48:02 volumio sudo[1080]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:02 volumio volumio[1012]: info: Loading plugin "volumio5onboarding"... Apr 11 17:48:02 volumio sudo[1089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 11 17:48:02 volumio sudo[1089]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:02 volumio volumio[1012]: info: Loading plugin "alsa_controller"... Apr 11 17:48:02 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 17:48:02 volumio volumio[1012]: info: Loading plugin "wizard"... Apr 11 17:48:02 volumio volumio[1012]: info: Loading plugin "networkfs"... Apr 11 17:48:02 volumio volumio[1012]: info: Starting Udev Watcher for removable devices Apr 11 17:48:02 volumio volumio[1012]: info: Ignoring mount for partition: boot Apr 11 17:48:02 volumio volumio[1012]: info: Ignoring mount for partition: volumio Apr 11 17:48:02 volumio volumio[1012]: info: Ignoring mount for partition: volumio_data Apr 11 17:48:02 volumio volumio[1012]: error: Cannot associate FS Label, not mounting Apr 11 17:48:02 volumio volumio[1012]: info: Mounting Device media Apr 11 17:48:02 volumio sudo[1109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/media -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 17:48:02 volumio sudo[1109]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:05 volumio sudo[1089]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:06 volumio ntfs-3g[1112]: Version 2017.3.23AR.3 integrated FUSE 28 Apr 11 17:48:06 volumio ntfs-3g[1112]: Mounted /dev/sda2 (Read-Write, label "media", NTFS 3.1) Apr 11 17:48:06 volumio ntfs-3g[1112]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 17:48:06 volumio ntfs-3g[1112]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda2,blkdev,blksize=4096 Apr 11 17:48:06 volumio ntfs-3g[1112]: Global ownership and permissions enforced, configuration type 7 Apr 11 17:48:06 volumio sudo[1109]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:06 volumio volumio[1012]: The disk contains an unclean file system (0, 0). Apr 11 17:48:06 volumio volumio[1012]: The file system wasn't safely closed on Windows. Fixing. Apr 11 17:48:06 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 17:48:06 volumio volumio[1012]: info: Loading plugin "volumio_command_line_client"... Apr 11 17:48:06 volumio volumio[1012]: info: Loading plugin "upnp"... Apr 11 17:48:06 volumio volumio[1012]: info: [1775922486127] Starting Upmpd Daemon Apr 11 17:48:06 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 17:48:06 volumio volumio[1012]: info: Loading plugin "my_music"... Apr 11 17:48:06 volumio volumio[1012]: info: Loading plugin "mpd"... Apr 11 17:48:07 volumio volumio[1012]: info: Loading plugin "upnp_browser"... Apr 11 17:48:07 volumio volumio[1012]: info: Starting UPNP Browser Apr 11 17:48:07 volumio volumio[1012]: info: Loading plugin "alarm-clock"... Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "airplay_emulation"... Apr 11 17:48:08 volumio volumio[1012]: info: Starting Shairport Sync Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "last_100"... Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "webradio"... Apr 11 17:48:08 volumio systemd[1]: systemd-fsckd.service: Succeeded. Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "i2s_dacs"... Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "volumiodiscovery"... Apr 11 17:48:08 volumio volumio[1012]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 17:48:08 volumio node[1012]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 17:48:08 volumio node[1012]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 17:48:08 volumio volumio[1012]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 17:48:08 volumio volumio[1012]: *** WARNING *** For more information see Apr 11 17:48:08 volumio volumio[1012]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 17:48:08 volumio volumio[1012]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 17:48:08 volumio volumio[1012]: *** WARNING *** For more information see Apr 11 17:48:08 volumio node[1012]: *** WARNING *** For more information see Apr 11 17:48:08 volumio node[1012]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 17:48:08 volumio node[1012]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 17:48:08 volumio node[1012]: *** WARNING *** For more information see Apr 11 17:48:08 volumio volumio[1012]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 11 17:48:08 volumio volumio[1012]: info: Discovery: Started advertising with name: Volumio Apr 11 17:48:08 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "outputs"... Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "albumart"... Apr 11 17:48:08 volumio volumio[1012]: info: Plugin example_plugin is not enabled Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "inputs"... Apr 11 17:48:08 volumio volumio[1012]: info: Loading plugin "updater_comm"... Apr 11 17:48:09 volumio volumio[1012]: info: Plugin mpdemulation is not enabled Apr 11 17:48:09 volumio volumio[1012]: info: Loading plugin "rest_api"... Apr 11 17:48:09 volumio volumio[1012]: info: Loading plugin "websocket"... Apr 11 17:48:09 volumio volumio[1012]: info: Starting Socket.io Server version 2.3.0 Apr 11 17:48:09 volumio volumio[1012]: info: Loading plugin "radio_paradise"... Apr 11 17:48:09 volumio volumio[1012]: Forking 3 albumart workers Apr 11 17:48:10 volumio volumio[1012]: info: Applying required configuration parameters for plugin radio_paradise Apr 11 17:48:10 volumio volumio[1012]: info: [1775922490236] [RadioParadise] API delay: 5 Apr 11 17:48:10 volumio volumio[1012]: info: Loading i18n strings for locale de Apr 11 17:48:10 volumio volumio[1012]: Updating browse sources language Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 17:48:10 volumio volumio-remote-updater[605]: [2026-04-11 17:48:10] [connect] Successful connection Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::initPlayerControls Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:10 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 17:48:11 volumio volumio[1012]: Express server listening on port 3000 Apr 11 17:48:11 volumio volumio[1012]: [Metrics] WebUI: 15s 936.71ms Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::resetVolumioState Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::getcurrentVolume Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 17:48:11 volumio volumio[1012]: info: Volumio Network Manager: Network status updated: 1 Apr 11 17:48:11 volumio volumio-remote-updater[605]: [2026-04-11 17:48:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1775922490 101 Apr 11 17:48:11 volumio volumio[1012]: Starting albumart workers Apr 11 17:48:11 volumio volumio[1012]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Apr 11 17:48:11 volumio volumio[1012]: Starting albumart workers Apr 11 17:48:11 volumio volumio[1012]: Starting albumart workers Apr 11 17:48:11 volumio volumio[1012]: info: Reloading queue from file Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::setRepeat null single undefined Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:48:11 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::setRandom true Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:48:11 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:48:11 volumio volumio[1012]: info: VolumeController:: Volume=94 Mute =false Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:48:11 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:48:11 volumio volumio[1012]: info: CoreStateMachine::updateTrackBlock Apr 11 17:48:11 volumio volumio[1012]: info: CorePlayQueue::getTrackBlock Apr 11 17:48:11 volumio volumio[1012]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 17:48:11 volumio volumio[1012]: info: Setting Device type: Raspberry PI Apr 11 17:48:11 volumio volumio[1012]: info: Completed loading Core Plugins Apr 11 17:48:11 volumio volumio[1012]: info: Preparing to generate the ALSA configuration file Apr 11 17:48:12 volumio volumio[1012]: info: Asound.conf file unchanged, so no further update is needed Apr 11 17:48:12 volumio volumio[1012]: info: Output device has changed, restarting MPD Apr 11 17:48:12 volumio sudo[1158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 17:48:12 volumio sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:12 volumio volumio[1012]: info: Output device has changed, restarting Shairport Sync Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:12 volumio sudo[1158]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:12 volumio sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 17:48:12 volumio sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:12 volumio volumio[1012]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 17:48:12 volumio volumio[1012]: info: ___________ START PLUGINS ___________ Apr 11 17:48:12 volumio systemd[1]: Listening on mpd.socket. Apr 11 17:48:12 volumio volumio[1012]: info: ControllerMpd::onStart: Initializing MPD Apr 11 17:48:12 volumio systemd[1]: Starting Music Player Daemon... Apr 11 17:48:12 volumio volumio[1012]: info: Creating MPD Configuration file Apr 11 17:48:12 volumio sudo[1182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 11 17:48:12 volumio sudo[1182]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 17:48:12 volumio volumio[1012]: info: [1775922492533] CoreMusicLibrary::Adding element Medienserver Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 17:48:12 volumio sudo[1185]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 17:48:12 volumio sudo[1185]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:12 volumio volumio[1012]: info: UPNP Browser: Client initialized successfully Apr 11 17:48:12 volumio systemd[1]: Started Volumio5 Onboarding Server. Apr 11 17:48:12 volumio sudo[1185]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:12 volumio sudo[1188]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 17:48:12 volumio sudo[1188]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:12 volumio sudo[1182]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:12 volumio sudo[1183]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 17:48:12 volumio sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:12 volumio sudo[1183]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 11 17:48:12 volumio sudo[1183]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:12 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 11 17:48:12 volumio systemd[1]: mpd.service: Succeeded. Apr 11 17:48:12 volumio systemd[1]: Stopped Music Player Daemon. Apr 11 17:48:12 volumio systemd[1]: Starting Music Player Daemon... Apr 11 17:48:12 volumio volumio[1012]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:12 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:13 volumio volumio[1012]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 17:48:13 volumio volumio[1012]: info: [1775922493052] CoreMusicLibrary::Adding element Last_100 Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 17:48:13 volumio volumio[1012]: info: [1775922493076] CoreMusicLibrary::Adding element Webradio Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 17:48:13 volumio volumio[1012]: info: Initializing BBC Radios Apr 11 17:48:13 volumio sudo[1196]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 17:48:13 volumio sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:13 volumio sudo[1196]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 11 17:48:13 volumio sudo[1196]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 17:48:13 volumio volumio[1012]: info: [1775922493547] CoreMusicLibrary::Adding element Radio Paradise Apr 11 17:48:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 17:48:13 volumio volumio[1012]: Cannot find translation for source Radio Paradise Apr 11 17:48:13 volumio volumio[1012]: info: Volumio Calling Home Apr 11 17:48:13 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:13.822+02:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 11 17:48:14 volumio volumio[1012]: info: Discovery: adding 0d0c80c3-7c8b-4bb7-ae7c-cf3ff518b215 Apr 11 17:48:14 volumio volumio[1012]: info: Discovery: Found device Volumio Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:14 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:14 volumio volumio[1012]: info: MPD Permissions set Apr 11 17:48:14 volumio volumio[1012]: info: MPD Permissions set Apr 11 17:48:14 volumio volumio[1012]: info: VolumeController:: Volume=94 Mute =false Apr 11 17:48:14 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:48:14 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:48:14 volumio volumio[1012]: info: Discovery: this is already registered, 0d0c80c3-7c8b-4bb7-ae7c-cf3ff518b215 Apr 11 17:48:14 volumio volumio[1012]: info: Discovery: Found device Volumio Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:14 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:14 volumio volumio[1012]: 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 11 17:48:14 volumio volumio[1012]: info: Volumio called home Apr 11 17:48:14 volumio volumio[1012]: 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 11 17:48:14 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:14 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:14 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:14 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:14.381+02:00 level=INFO msg="system info for 8ae43bb2f70c9588fd98dd48959bacce" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=3.912 Apr 11 17:48:14 volumio volumio[1012]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:14 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:14 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:14 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:14 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 17:48:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:15.047+02:00 level=INFO msg="enabling local network discovery" Apr 11 17:48:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:15.080+02:00 level=INFO msg="enabling BLE discovery" Apr 11 17:48:15 volumio volumio[1012]: info: Starting Shairport Sync Apr 11 17:48:15 volumio bluetoothd[751]: src/adapter.c:store_adapter_info() Unable set contents for /usr/var/lib/bluetooth/B8:27:EB:AB:DC:D2/settings: (Failed to create file “/usr/var/lib/bluetooth/B8:27:EB:AB:DC:D2/settings.NCCJN3”: No such file or directory) Apr 11 17:48:15 volumio volumio[1012]: info: Starting Shairport Sync Apr 11 17:48:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:15.181+02:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 11 17:48:15 volumio volumio[1012]: info: Starting Shairport Sync Apr 11 17:48:15 volumio sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 17:48:15 volumio sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:15 volumio sudo[1263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 17:48:15 volumio sudo[1263]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:15 volumio sudo[1266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 17:48:15 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 11 17:48:15 volumio sudo[1266]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:15 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 11 17:48:15 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:15 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:15 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 11 17:48:15 volumio volumio-remote-updater[605]: No test mode Apr 11 17:48:15 volumio volumio-remote-updater[605]: No alpha test mode Apr 11 17:48:15 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 11 17:48:15 volumio sudo[1261]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:15 volumio volumio[1012]: info: Shairport-Sync Started Apr 11 17:48:15 volumio volumio[1012]: Error adding Membership: Error: addMembership EINVAL Apr 11 17:48:15 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 11 17:48:15 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 11 17:48:15 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 11 17:48:15 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 11 17:48:15 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 11 17:48:15 volumio sudo[1263]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:15 volumio volumio[1012]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 11 17:48:15 volumio sudo[1266]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 17:48:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:15.575+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Apr 11 17:48:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:15.577+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Apr 11 17:48:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:15.577+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Apr 11 17:48:15 volumio volumio[1012]: info: Shairport-Sync Started Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 17:48:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 17:48:16 volumio sudo[1276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 17:48:16 volumio sudo[1276]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:16 volumio sudo[1276]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:16 volumio sudo[1278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 17:48:16 volumio sudo[1278]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:16 volumio sudo[1278]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:16 volumio sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 11 17:48:16 volumio sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:16 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 11 17:48:16 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:16.417+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 11 17:48:16 volumio sudo[1281]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:16 volumio volumio[1012]: info: Upmpdcli Daemon Started Apr 11 17:48:18 volumio mpd[1216]: Apr 11 17:48 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 17:48:18 volumio systemd[1]: Started Music Player Daemon. Apr 11 17:48:18 volumio volumio[1012]: Upnp client error: Error: This socket has been ended by the other party Apr 11 17:48:18 volumio sudo[1188]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:18 volumio sudo[1165]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:18 volumio volumio[1012]: info: Completed starting Core Plugins Apr 11 17:48:18 volumio volumio[1012]: info: ------------------------------------------- Apr 11 17:48:18 volumio volumio[1012]: info: ----- MyVolumio plugins startup ---- Apr 11 17:48:18 volumio volumio[1012]: info: ------------------------------------------- Apr 11 17:48:18 volumio volumio[1012]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 11 17:48:19 volumio systemd[1]: systemd-timedated.service: Succeeded. Apr 11 17:48:19 volumio volumio[1012]: error: MPD error: The expression evaluated to a falsy value: Apr 11 17:48:19 volumio volumio[1012]: assert.ok(self.idling) Apr 11 17:48:19 volumio volumio[1012]: error: The expression evaluated to a falsy value: Apr 11 17:48:19 volumio volumio[1012]: assert.ok(self.idling) Apr 11 17:48:19 volumio volumio[1012]: error: updateQueue error: null Apr 11 17:48:19 volumio volumio[1012]: info: MPD running with PID1216 Apr 11 17:48:19 volumio volumio[1012]: ,establishing connection Apr 11 17:48:19 volumio volumio[1012]: error: updateQueue error: null Apr 11 17:48:20 volumio volumio[1284]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 11 17:48:27 volumio volumio[1012]: info: Adding plugin bluetooth to MyMusic Plugins Apr 11 17:48:27 volumio volumio[1012]: info: Adding plugin multiroom to MyMusic Plugins Apr 11 17:48:27 volumio volumio[1012]: info: Adding plugin metavolumio to MyMusic Plugins Apr 11 17:48:27 volumio volumio[1012]: info: Adding plugin cd_controller to MyMusic Plugins Apr 11 17:48:27 volumio volumio[1012]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 11 17:48:27 volumio volumio[1012]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 11 17:48:27 volumio volumio[1012]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 11 17:48:27 volumio volumio[1012]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 11 17:48:30 volumio volumio[1012]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 11 17:48:30 volumio volumio[1012]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 11 17:48:30 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:30 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:30 volumio volumio[1012]: info: Starting MyVolumio Remote Streaming Endpoints Apr 11 17:48:30 volumio volumio[1012]: info: MyVolumio login type: Token Apr 11 17:48:30 volumio volumio[1012]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 11 17:48:30 volumio volumio[1012]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 11 17:48:32 volumio volumio[1012]: info: Starting Streaming Service Transparent Proxy Apr 11 17:48:32 volumio volumio[1012]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 17:48:32 volumio volumio[1012]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 17:48:32 volumio volumio[1012]: info: Streaming services startup Apr 11 17:48:32 volumio volumio[1012]: info: Starting Streaming Daemon Apr 11 17:48:32 volumio sudo[1341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 17:48:32 volumio sudo[1341]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:32 volumio volumio[1012]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 17:48:32 volumio sudo[1341]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:33 volumio volumio[1012]: error: Cannot start Volumio Streaming Daemon Apr 11 17:48:33 volumio volumio[1012]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 17:48:33 volumio volumio[1012]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 17:48:33 volumio volumio[1012]: error: MyVolumio Custom Token format not valid, refreshing it Apr 11 17:48:34 volumio volumio[1012]: info: MyVolumio login type: Token Apr 11 17:48:34 volumio volumio[1012]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 17:48:34 volumio volumio[1012]: STREAMING PROXY: Starting server on port 3245 Apr 11 17:48:34 volumio volumio[1012]: Node JS runtime: 14 Apr 11 17:48:35 volumio volumio[1012]: info: MyVolumio token set successfully Apr 11 17:48:35 volumio volumio[1012]: info: MYVOLUMIO: Adding device Apr 11 17:48:35 volumio volumio[1012]: info: MYVOLUMIO: Evaluating Server Apr 11 17:48:35 volumio volumio[1012]: info: MyVolumio status changed Apr 11 17:48:35 volumio volumio[1012]: info: Streaming services startup Apr 11 17:48:35 volumio volumio[1012]: info: Starting Streaming Daemon Apr 11 17:48:35 volumio volumio[1012]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 17:48:35 volumio volumio[1012]: info: Removing audio output: Apr 11 17:48:35 volumio volumio[1012]: info: Stoppping Tunnel 1 Apr 11 17:48:35 volumio sudo[1369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 17:48:35 volumio sudo[1369]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:35 volumio sudo[1371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 11 17:48:35 volumio sudo[1371]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:35 volumio sudo[1369]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:35 volumio volumio[1012]: error: Cannot start Volumio Streaming Daemon Apr 11 17:48:35 volumio volumio[1012]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 17:48:35 volumio volumio[1012]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 17:48:35 volumio sudo[1371]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:35 volumio volumio[1012]: info: Remote SSH Stopped Apr 11 17:48:40 volumio volumio[1012]: info: Setting Geolocation for MyVolumio to eu4 Apr 11 17:48:40 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:40 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:40 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:41 volumio volumio[1012]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 11 17:48:41 volumio volumio[1012]: info: Updating MyVolumio device info Apr 11 17:48:41 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:41 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:42 volumio volumio[1012]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 11 17:48:43 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 17:48:43 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:43 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 17:48:43 volumio volumio-remote-updater[605]: No test mode Apr 11 17:48:43 volumio volumio-remote-updater[605]: No alpha test mode Apr 11 17:48:43 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 11 17:48:43 volumio volumio[1012]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 11 17:48:43 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 11 17:48:45 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 17:48:45 volumio volumio[1012]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 11 17:48:45 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:45 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:45 volumio volumio[1012]: info: MYVOLUMIO: Adding device Apr 11 17:48:45 volumio volumio[1012]: info: MYVOLUMIO: Evaluating Server Apr 11 17:48:45 volumio volumio[1284]: .....................................................................................................++++ Apr 11 17:48:48 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:48.963+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.178.42:50112 Apr 11 17:48:49 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:49 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:49 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:49 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:49 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:49 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:49 volumio volumio[1012]: verbose: New Socket.io Connection to 192.168.178.79:3000 from 192.168.178.42 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Apr 11 17:48:49 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 17:48:49 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::volumioGetBrowseSources Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.116+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.178.42:50112 @ 0x1ade8d0" latency=-1.307739461s platform=PLATFORM_ANDROID version=5.260331.0 Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.117+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.178.42:50112 @ 0x1ade8d0" latency=-1.307182908s timeout=10s Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.117+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 17:48:50 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:50 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:50 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.128+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" name=Volumio Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.133+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" language=de Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.137+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" timezone=Europe/Vienna Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.138+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" available=true connected=true macAddress=b8:27:eb:01:76:78 ip4Address=192.168.178.79/24 ip6Address= Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.140+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.141+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" setupComplete=true Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 17:48:50 volumio volumio[1012]: amixer -c 2 info | grep "snd_rpi_hifiberry_dacplus" Apr 11 17:48:50 volumio volumio[1012]: Card hw:2 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Apr 11 17:48:50 volumio volumio[1012]: amixer -c 0 info | grep "bcm2835 ALSA" Apr 11 17:48:50 volumio volumio[1012]: amixer -c 1 info | grep "bcm2835 Headphones" Apr 11 17:48:50 volumio volumio[1012]: Card hw:1 'Headphones'/'bcm2835 Headphones' Apr 11 17:48:50 volumio volumio[1012]: amixer -c 2 info | grep "snd_rpi_hifiberry_dacplus" Apr 11 17:48:50 volumio volumio[1012]: Card hw:2 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.545+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" selectedOutputId=2 Apr 11 17:48:50 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:50 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:50 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.572+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" currentVersion=3.912 latestVersion=3.912 Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.573+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" status=UPDATE_STATUS_NONE progress=0 Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.575+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" userId= Apr 11 17:48:50 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:50.576+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" providers=3 Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 17:48:50 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 11 17:48:51 volumio volumio[1012]: info: Setting Geolocation for MyVolumio to eu6 Apr 11 17:48:51 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:51 volumio ntpd[773]: Soliciting pool server 152.53.129.213 Apr 11 17:48:51 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:51.286+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" plugins=54 Apr 11 17:48:51 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:51 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:51 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:51.301+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_STOPPED positionMs=0 volume=94 Apr 11 17:48:51 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:51.303+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="music-library/USB/media/London Grammar - Californian Soil/01 - Intro.flac" title=Intro Apr 11 17:48:51 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:51.328+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.42:50112 @ 0x1ade8d0" latency=-1.312634774s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Apr 11 17:48:52 volumio volumio[1012]: info: Updating MyVolumio device info Apr 11 17:48:52 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:52 volumio ntpd[773]: Soliciting pool server 178.251.64.52 Apr 11 17:48:52 volumio volumio[1012]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 11 17:48:52 volumio volumio[1012]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 11 17:48:52 volumio volumio[1012]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 11 17:48:52 volumio volumio[1012]: info: Completed starting MyVolumio Plugin Apr 11 17:48:52 volumio volumio[1012]: [Metrics] CommandRouter: 56s 191.28ms Apr 11 17:48:52 volumio volumio[1012]: info: CoreCommandRouter::volumiosetStartupVolume Apr 11 17:48:52 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 17:48:52 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:53 volumio volumio[1012]: info: CoreCommandRouter::Close All Modals sent Apr 11 17:48:53 volumio volumio[1012]: info: CoreCommandRouter::Close All Modals sent Apr 11 17:48:53 volumio ntpd[773]: Soliciting pool server 162.159.200.1 Apr 11 17:48:53 volumio ntpd[773]: Soliciting pool server 185.144.161.170 Apr 11 17:48:53 volumio ntpd[773]: Soliciting pool server 217.175.196.134 Apr 11 17:48:53 volumio sudo[1479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 17:48:53 volumio sudo[1479]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:53 volumio sudo[1479]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:53 volumio sudo[1481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 17:48:53 volumio sudo[1481]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:53 volumio sudo[1481]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:53 volumio volumio[1012]: verbose: New Socket.io Connection to 192.168.178.79 from 192.168.178.42 UA: Mozilla/5.0 (Linux; Android 16; SM-S918B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Apr 11 17:48:53 volumio sudo[1485]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 17:48:53 volumio sudo[1485]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:53 volumio sudo[1485]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:53 volumio sudo[1487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 17:48:53 volumio sudo[1487]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 17:48:53 volumio sudo[1487]: pam_unix(sudo:session): session closed for user root Apr 11 17:48:54 volumio volumio[1012]: verbose: New Socket.io Connection to 192.168.178.79 from 192.168.178.42 UA: Mozilla/5.0 (Linux; Android 16; SM-S918B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 11 17:48:54 volumio ntpd[773]: Soliciting pool server 152.53.119.76 Apr 11 17:48:54 volumio ntpd[773]: Soliciting pool server 152.53.15.127 Apr 11 17:48:54 volumio ntpd[773]: Soliciting pool server 152.53.119.76 Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:54 volumio volumio[1284]: ....................................++++ Apr 11 17:48:54 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:54 volumio volumio[1284]: e is 65537 (0x010001) Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 17:48:54 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:54 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:54 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:54 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:54 volumio volumio[1012]: info: Listing playlists Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 11 17:48:54 volumio volumio[1284]: writing RSA key Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 17:48:54 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 11 17:48:55 volumio ntpd[773]: Soliciting pool server 46.102.157.67 Apr 11 17:48:55 volumio ntpd[773]: Soliciting pool server 152.53.102.196 Apr 11 17:48:55 volumio volumio[1012]: info: CoreCommandRouter::volumioGetQueue Apr 11 17:48:55 volumio volumio[1012]: info: CoreStateMachine::getQueue Apr 11 17:48:55 volumio volumio[1012]: info: CorePlayQueue::getQueue Apr 11 17:48:55 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:55.843+02:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Apr 11 17:48:55 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 11 17:48:55 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 17:48:55 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:55 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:55 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:55 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:55 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:55 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:55 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:55 volumio dbus-daemon[593]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.16" (uid=0 pid=1189 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=751 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.027+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.178.42:50112 @ 0x1ade8d0" latency=-1.314051139s timeout=10s Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.027+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.027+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.178.42:50112 @ 0x1ade8d0" latency=-1.313258638s platform=PLATFORM_ANDROID version=5.260331.0 Apr 11 17:48:56 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:56 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:56 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.058+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" name=Volumio Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.064+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" language=de Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 11 17:48:56 volumio ntpd[773]: Soliciting pool server 5.45.97.204 Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.101+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" timezone=Europe/Vienna Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.107+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" available=true connected=true macAddress=b8:27:eb:01:76:78 ip4Address=192.168.178.79/24 ip6Address= Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.117+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.117+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" setupComplete=true Apr 11 17:48:56 volumio ntpd[773]: Soliciting pool server 152.53.100.131 Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 17:48:56 volumio volumio[1012]: amixer -c 2 info | grep "snd_rpi_hifiberry_dacplus" Apr 11 17:48:56 volumio volumio[1012]: Card hw:2 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Apr 11 17:48:56 volumio volumio[1012]: amixer -c 0 info | grep "bcm2835 ALSA" Apr 11 17:48:56 volumio volumio[1012]: amixer -c 1 info | grep "bcm2835 Headphones" Apr 11 17:48:56 volumio volumio[1012]: Card hw:1 'Headphones'/'bcm2835 Headphones' Apr 11 17:48:56 volumio volumio[1012]: amixer -c 2 info | grep "snd_rpi_hifiberry_dacplus" Apr 11 17:48:56 volumio volumio[1012]: Card hw:2 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.587+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" selectedOutputId=2 Apr 11 17:48:56 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:56 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:56 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.645+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" currentVersion=3.912 latestVersion=3.912 Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.646+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" status=UPDATE_STATUS_NONE progress=0 Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.647+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" userId= Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.648+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" providers=3 Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.648+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" plugins=54 Apr 11 17:48:56 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:56 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.685+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_STOPPED positionMs=0 volume=94 Apr 11 17:48:56 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:56.686+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="music-library/USB/media/London Grammar - Californian Soil/01 - Intro.flac" title=Intro Apr 11 17:48:57 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 17:48:57 volumio volumio[1012]: info: Received Get System Info Apr 11 17:48:57 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:48:57 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:48:57 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:48:57 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:48:57 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:48:57 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:48:57 volumio ntpd[773]: Soliciting pool server 90.146.44.205 Apr 11 17:48:57 volumio ntpd[773]: Soliciting pool server 2a12:bec0:2c7:13a9::123 Apr 11 17:48:57 volumio volumio5-onboarding[1189]: time=2026-04-11T17:48:57.226+02:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Apr 11 17:48:58 volumio ntpd[773]: Soliciting pool server 37.252.189.117 Apr 11 17:49:00 volumio ntpd[773]: receive: Unexpected origin timestamp 0xed84ebeb.19ef0778 does not match aorg 0000000000.00000000 from server@152.53.119.76 xmt 0xed84ebec.4415c54c Apr 11 17:49:00 volumio ntpd[773]: receive: Unexpected origin timestamp 0xed84ebeb.19ecd453 does not match aorg 0000000000.00000000 from server@5.45.97.204 xmt 0xed84ebec.44bd6d54 Apr 11 17:49:01 volumio volumio[1012]: info: BOOT COMPLETED Apr 11 17:49:05 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 11 17:49:09 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 11 17:49:09 volumio volumio[1012]: info: CURURI: music-library/USB/media/Heilung Apr 11 17:49:09 volumio volumio[1012]: info: Preload queue cleared Apr 11 17:49:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 17:49:13 volumio volumio[1012]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 11 17:49:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 11 17:49:13 volumio volumio[1012]: info: Received Get System Version Apr 11 17:49:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 17:49:13 volumio volumio[1012]: info: Received Get System Info Apr 11 17:49:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 17:49:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 17:49:13 volumio volumio[1012]: info: Discovery: Getting this device information Apr 11 17:49:13 volumio volumio[1012]: info: CoreCommandRouter::volumioGetState Apr 11 17:49:13 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:13 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 17:49:14 volumio volumio[1012]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 17:49:14 volumio volumio[1012]: info: CoreStateMachine::ClearQueue Apr 11 17:49:14 volumio volumio[1012]: info: CoreStateMachine::stop Apr 11 17:49:14 volumio volumio[1012]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 17:49:14 volumio volumio[1012]: info: CorePlayQueue::clearPlayQueue Apr 11 17:49:14 volumio volumio[1012]: info: CorePlayQueue::saveQueue Apr 11 17:49:14 volumio volumio[1012]: info: CoreCommandRouter::volumioPushQueue Apr 11 17:49:14 volumio volumio[1012]: info: CoreStateMachine::addQueueItems Apr 11 17:49:14 volumio volumio[1012]: info: CorePlayQueue::addQueueItems Apr 11 17:49:14 volumio volumio[1012]: info: Preload queue cleared Apr 11 17:49:14 volumio volumio[1012]: info: Adding Item to queue: music-library/USB/media/Heilung/Heilung - Futha Apr 11 17:49:14 volumio volumio[1012]: info: Exploding uri music-library/USB/media/Heilung/Heilung - Futha in service mpd Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2001%20Galgaldr.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2002%20Norupo.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 02 Norupo.flac Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2003%20Othan.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 03 Othan.flac Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2004%20Traust.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 04 Traust.flac Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2005%20Vapnatak.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 05 Vapnatak.flac Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2006%20Svanrand.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 06 Svanrand.flac Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2007%20Elivagar.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 07 Elivagar.flac Apr 11 17:49:15 volumio volumio[1012]: info: ALBUMART /albumart?cacheid=549&web=Heilung/Futha/extralarge&path=%2Fmnt%2FUSB%2Fmedia%2FHeilung%2FHeilung%20-%20Futha%2FHeilung%20-%20Futha%20-%2008%20Elddansurin.flac&metadata=false Apr 11 17:49:15 volumio volumio[1012]: info: URI /mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 08 Elddansurin.flac Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushQueue Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::saveQueue Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::updateTrackBlock Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrackBlock Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPlay Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::play index 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::stop Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::play index undefined Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::startPlaybackTimer Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::clearAddPlayTracks USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand stop took 12 milliseconds Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces system playlist update Apr 11 17:49:15 volumio volumio[1012]: info: Ignoring MPD Status Update Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand clear took 7 milliseconds Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand add "USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces system playlist update Apr 11 17:49:15 volumio volumio[1012]: info: Ignoring MPD Status Update Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces system playlist update Apr 11 17:49:15 volumio volumio[1012]: info: Ignoring MPD Status Update Apr 11 17:49:15 volumio volumio[1012]: error: updateQueue error: null Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces system playlist update Apr 11 17:49:15 volumio volumio[1012]: info: Ignoring MPD Status Update Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 22ms Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand add "USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" took 17 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 15ms Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 12ms Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand play Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces system playlist update Apr 11 17:49:15 volumio volumio[1012]: info: Ignoring MPD Status Update Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces system playlist update Apr 11 17:49:15 volumio volumio[1012]: info: Ignoring MPD Status Update Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces state update: player Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 21ms Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand play took 14 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 12ms Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 9ms Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::getState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand status Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces state update: player Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::getState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand status Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces state update: player Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::getState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand status Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces state update: player Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::getState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand status Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces state update: player Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::getState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand status Apr 11 17:49:15 volumio volumio[1012]: info: Apr 11 17:49:15 volumio volumio[1012]: ---------------------------- MPD announces state update: player Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::getState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand status Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand status took 40 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand status took 38 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand status took 35 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand status took 16 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand status took 13 milliseconds Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand status took 29 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand playlistinfo took 16 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand playlistinfo took 15 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseState Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseTrackInfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseTrackInfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseTrackInfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseTrackInfo Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseTrackInfo Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::servicePushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":622,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"462 Kbps","isStreaming":false,"title":"Galgaldr","artist":"Heilung","album":"Futha","uri":"USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac","trackType":"flac"} Apr 11 17:49:15 volumio volumio[1012]: verbose: CURRENT POSITION 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState stateService play Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState currentStatus stop Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::servicePushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":622,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"462 Kbps","isStreaming":false,"title":"Galgaldr","artist":"Heilung","album":"Futha","uri":"USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac","trackType":"flac"} Apr 11 17:49:15 volumio volumio[1012]: verbose: CURRENT POSITION 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState stateService play Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState currentStatus play Apr 11 17:49:15 volumio volumio[1012]: info: Received an update from plugin. extracting info from payload Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::servicePushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":622,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"484 Kbps","isStreaming":false,"title":"Galgaldr","artist":"Heilung","album":"Futha","uri":"USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac","trackType":"flac"} Apr 11 17:49:15 volumio volumio[1012]: verbose: CURRENT POSITION 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState stateService play Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState currentStatus play Apr 11 17:49:15 volumio volumio[1012]: info: Received an update from plugin. extracting info from payload Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::servicePushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":622,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"490 Kbps","isStreaming":false,"title":"Galgaldr","artist":"Heilung","album":"Futha","uri":"USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac","trackType":"flac"} Apr 11 17:49:15 volumio volumio[1012]: verbose: CURRENT POSITION 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState stateService play Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState currentStatus play Apr 11 17:49:15 volumio volumio[1012]: info: Received an update from plugin. extracting info from payload Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::servicePushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":622,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"527 Kbps","isStreaming":false,"title":"Galgaldr","artist":"Heilung","album":"Futha","uri":"USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac","trackType":"flac"} Apr 11 17:49:15 volumio volumio[1012]: verbose: CURRENT POSITION 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState stateService play Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState currentStatus play Apr 11 17:49:15 volumio volumio[1012]: info: Received an update from plugin. extracting info from payload Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 186ms Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.351+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.352+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.355+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.356+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.358+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.359+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.362+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.363+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.366+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.366+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.369+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.370+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.374+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.374+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.377+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.378+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 288ms Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 286ms Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 269ms Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 266ms Apr 11 17:49:15 volumio volumio[1012]: info: sendMpdCommand playlistinfo took 229 milliseconds Apr 11 17:49:15 volumio volumio[1012]: verbose: ControllerMpd::parseTrackInfo Apr 11 17:49:15 volumio volumio[1012]: info: ControllerMpd::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::servicePushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":622,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"492 Kbps","isStreaming":false,"title":"Galgaldr","artist":"Heilung","album":"Futha","uri":"USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac","trackType":"flac"} Apr 11 17:49:15 volumio volumio[1012]: verbose: CURRENT POSITION 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState stateService play Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::syncState currentStatus play Apr 11 17:49:15 volumio volumio[1012]: info: Received an update from plugin. extracting info from payload Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio[1012]: info: CoreStateMachine::pushState Apr 11 17:49:15 volumio volumio[1012]: info: CorePlayQueue::getTrack 0 Apr 11 17:49:15 volumio volumio[1012]: info: CoreCommandRouter::volumioPushState Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.482+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.483+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.486+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" state=STATUS_PLAYING positionMs=869 volume=94 Apr 11 17:49:15 volumio volumio5-onboarding[1189]: time=2026-04-11T17:49:15.487+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.42:50112 @ 0x1ade8d0" id="mnt/USB/media/Heilung/Heilung - Futha/Heilung - Futha - 01 Galgaldr.flac" title=Galgaldr Apr 11 17:49:15 volumio volumio[1012]: info: ------------------------------ 318ms Apr 11 17:49:15 volumio volumio[1012]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 17:49:16 volumio volumio[1012]: Error: getaddrinfo ENOTFOUND lastfm.freetls.fastly.net Apr 11 17:49:16 volumio volumio[1012]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Apr 11 17:49:16 volumio volumio[1012]: errno: -3007, Apr 11 17:49:16 volumio volumio[1012]: code: 'ENOTFOUND', Apr 11 17:49:16 volumio volumio[1012]: syscall: 'getaddrinfo', Apr 11 17:49:16 volumio volumio[1012]: hostname: 'lastfm.freetls.fastly.net' Apr 11 17:49:16 volumio volumio[1012]: } Apr 11 17:49:16 volumio volumio[1012]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 17:49:17 volumio sudo[1568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-11 17:48 Apr 11 17:49:17 volumio sudo[1568]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"