-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2026-04-12 08:37:43 CEST. -- Apr 12 08:36:07 volumio systemd-timedated[1000]: Changed local time to Sun Apr 12 08:36:07 2026 Apr 12 08:36:07 volumio sudo[998]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:07 volumio volumio-time-update[548]: volumio-time-update-util: System time updated successfully. Apr 12 08:36:07 volumio systemd[1]: Starting Daily man-db regeneration... Apr 12 08:36:07 volumio systemd[1]: Starting Daily apt download activities... Apr 12 08:36:07 volumio systemd[1]: Started Volumio Time Update Utility. Apr 12 08:36:07 volumio systemd[1]: Reached target Multi-User System. Apr 12 08:36:07 volumio systemd[1]: Reached target Graphical Interface. Apr 12 08:36:07 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 12 08:36:07 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 12 08:36:07 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 12 08:36:07 volumio systemd[1]: man-db.service: Succeeded. Apr 12 08:36:07 volumio systemd[1]: Started Daily man-db regeneration. Apr 12 08:36:07 volumio volumio[955]: info: MYVOLUMIO Environment detected Apr 12 08:36:08 volumio volumio[955]: info: Plugin folders cleanup Apr 12 08:36:08 volumio volumio[955]: info: Scanning into folder /volumio/app/plugins/ Apr 12 08:36:08 volumio volumio[955]: info: Scanning category audio_interface Apr 12 08:36:08 volumio volumio[955]: info: Scanning category miscellanea Apr 12 08:36:08 volumio volumio[955]: info: Scanning category music_service Apr 12 08:36:08 volumio volumio[955]: info: Scanning category plugins.json Apr 12 08:36:08 volumio volumio[955]: info: Scanning category system_controller Apr 12 08:36:08 volumio volumio[955]: info: Scanning category user_interface Apr 12 08:36:08 volumio volumio[955]: info: Scanning into folder /data/plugins/ Apr 12 08:36:08 volumio volumio[955]: info: Scanning category audio_interface Apr 12 08:36:08 volumio volumio[955]: info: Scanning category music_service Apr 12 08:36:08 volumio volumio[955]: info: Scanning category system_controller Apr 12 08:36:08 volumio volumio[955]: info: Scanning category system_hardware Apr 12 08:36:08 volumio volumio[955]: info: Scanning category user_interface Apr 12 08:36:08 volumio volumio[955]: info: Plugin folders cleanup completed Apr 12 08:36:08 volumio volumio[955]: info: ------------------------------------------- Apr 12 08:36:08 volumio volumio[955]: info: ----- Core plugins startup ---- Apr 12 08:36:08 volumio volumio[955]: info: ------------------------------------------- Apr 12 08:36:08 volumio volumio[955]: info: Loading plugins from folder /volumio/app/plugins/ Apr 12 08:36:08 volumio volumio[955]: info: Adding plugin upnp to MyMusic Plugins Apr 12 08:36:08 volumio volumio[955]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 12 08:36:08 volumio volumio[955]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 12 08:36:08 volumio volumio[955]: info: Loading plugins from folder /data/plugins/ Apr 12 08:36:08 volumio volumio[955]: info: Loading plugin "system"... Apr 12 08:36:08 volumio volumio[955]: info: Loading plugin "ampswitch"... Apr 12 08:36:08 volumio volumio-remote-updater[551]: [2026-04-12 08:36:08] [connect] Successful connection Apr 12 08:36:09 volumio volumio[955]: info: Applying required configuration parameters for plugin ampswitch Apr 12 08:36:09 volumio volumio[955]: info: Loading plugin "appearance"... Apr 12 08:36:10 volumio systemd[1]: apt-daily.service: Succeeded. Apr 12 08:36:10 volumio systemd[1]: Started Daily apt download activities. Apr 12 08:36:10 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "network"... Apr 12 08:36:11 volumio volumio[955]: info: Refreshing Cached IP Addresses Apr 12 08:36:11 volumio sudo[1082]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 08:36:11 volumio sudo[1084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 08:36:11 volumio sudo[1082]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:11 volumio sudo[1084]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:11 volumio sudo[1082]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "services"... Apr 12 08:36:11 volumio sudo[1084]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "volumio5onboarding"... Apr 12 08:36:11 volumio sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 12 08:36:11 volumio sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "alsa_controller"... Apr 12 08:36:11 volumio sudo[1093]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:11 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "wizard"... Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "networkfs"... Apr 12 08:36:11 volumio volumio[955]: info: Starting Udev Watcher for removable devices Apr 12 08:36:11 volumio volumio[955]: info: Ignoring mount for partition: boot Apr 12 08:36:11 volumio volumio[955]: info: Ignoring mount for partition: volumio Apr 12 08:36:11 volumio volumio[955]: info: Ignoring mount for partition: volumio_data Apr 12 08:36:11 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "volumio_command_line_client"... Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "upnp"... Apr 12 08:36:11 volumio volumio[955]: info: [1775975771412] Starting Upmpd Daemon Apr 12 08:36:11 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "my_music"... Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "mpd"... Apr 12 08:36:11 volumio volumio[955]: info: Loading plugin "upnp_browser"... Apr 12 08:36:12 volumio volumio[955]: info: Starting UPNP Browser Apr 12 08:36:12 volumio volumio[955]: info: Loading plugin "alarm-clock"... Apr 12 08:36:12 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Apr 12 08:36:12 volumio systemd[1]: Started Daily apt upgrade and clean activities. Apr 12 08:36:12 volumio systemd[1]: Startup finished in 13.135s (kernel) + 21.592s (userspace) = 34.727s. Apr 12 08:36:12 volumio volumio[955]: info: Loading plugin "airplay_emulation"... Apr 12 08:36:12 volumio volumio[955]: info: Starting Shairport Sync Apr 12 08:36:12 volumio volumio[955]: info: Loading plugin "last_100"... Apr 12 08:36:12 volumio volumio[955]: info: Loading plugin "webradio"... Apr 12 08:36:12 volumio volumio[955]: info: Loading plugin "i2s_dacs"... Apr 12 08:36:12 volumio volumio[955]: info: Loading plugin "volumiodiscovery"... Apr 12 08:36:12 volumio volumio[955]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 08:36:12 volumio volumio[955]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 08:36:12 volumio volumio[955]: *** WARNING *** For more information see Apr 12 08:36:12 volumio volumio[955]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 08:36:12 volumio volumio[955]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 08:36:12 volumio node[955]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 08:36:12 volumio volumio[955]: *** WARNING *** For more information see Apr 12 08:36:12 volumio node[955]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 08:36:12 volumio node[955]: *** WARNING *** For more information see Apr 12 08:36:12 volumio node[955]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 08:36:12 volumio node[955]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 08:36:12 volumio node[955]: *** WARNING *** For more information see Apr 12 08:36:12 volumio volumio[955]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 12 08:36:12 volumio volumio[955]: info: Discovery: Started advertising with name: Volumio Apr 12 08:36:12 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 08:36:12 volumio volumio[955]: info: Loading plugin "autostart"... Apr 12 08:36:13 volumio volumio[955]: info: Applying required configuration parameters for plugin autostart Apr 12 08:36:13 volumio volumio[955]: info: AutoStart - onVolumioStart - read config.json Apr 12 08:36:13 volumio volumio[955]: info: Loading plugin "now_playing"... Apr 12 08:36:15 volumio volumio[955]: info: Loading plugin "outputs"... Apr 12 08:36:15 volumio volumio[955]: info: Loading plugin "albumart"... Apr 12 08:36:15 volumio volumio[955]: info: Plugin example_plugin is not enabled Apr 12 08:36:15 volumio volumio[955]: info: Loading plugin "inputs"... Apr 12 08:36:15 volumio volumio[955]: info: Loading plugin "updater_comm"... Apr 12 08:36:15 volumio volumio[955]: info: Plugin mpdemulation is not enabled Apr 12 08:36:15 volumio volumio[955]: info: Loading plugin "rest_api"... Apr 12 08:36:15 volumio volumio[955]: info: Loading plugin "websocket"... Apr 12 08:36:15 volumio volumio[955]: info: Starting Socket.io Server version 2.3.0 Apr 12 08:36:15 volumio volumio[955]: info: Loading plugin "fusiondsp"... Apr 12 08:36:15 volumio volumio[955]: Forking 3 albumart workers Apr 12 08:36:15 volumio volumio[955]: info: Applying required configuration parameters for plugin fusiondsp Apr 12 08:36:16 volumio volumio[955]: info: Loading plugin "mpdoutput"... Apr 12 08:36:16 volumio volumio[955]: info: Loading plugin "80s80s"... Apr 12 08:36:16 volumio volumio[955]: Starting albumart workers Apr 12 08:36:16 volumio volumio[955]: Starting albumart workers Apr 12 08:36:16 volumio volumio[955]: Starting albumart workers Apr 12 08:36:16 volumio volumio[955]: info: Applying required configuration parameters for plugin 80s80s Apr 12 08:36:16 volumio volumio[955]: info: [1775975776911] [80s80s] API delay: 30 Apr 12 08:36:16 volumio volumio[955]: info: Loading plugin "mpd_oled"... Apr 12 08:36:17 volumio volumio[955]: info: Applying required configuration parameters for plugin mpd_oled Apr 12 08:36:17 volumio volumio[955]: info: [MPD_OLED Plugin] Reading configuration file at: /data/configuration/system_hardware/mpd_oled/config.json Apr 12 08:36:17 volumio volumio[955]: info: Loading plugin "Systeminfo"... Apr 12 08:36:17 volumio volumio[955]: info: Loading plugin "ferrum_streaming_control_technology"... Apr 12 08:36:18 volumio volumio[955]: info: Applying required configuration parameters for plugin ferrum_streaming_control_technology Apr 12 08:36:18 volumio volumio[955]: info: Loading plugin "touch_display"... Apr 12 08:36:18 volumio volumio[955]: info: Applying required configuration parameters for plugin touch_display Apr 12 08:36:18 volumio volumio[955]: info: Loading i18n strings for locale fr Apr 12 08:36:18 volumio volumio[955]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Apr 12 08:36:18 volumio volumio[955]: Updating browse sources language Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::initPlayerControls Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:18 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 08:36:18 volumio volumio[955]: Express server listening on port 3000 Apr 12 08:36:18 volumio volumio[955]: [Metrics] WebUI: 13s 610.90ms Apr 12 08:36:19 volumio volumio[955]: info: CoreStateMachine::resetVolumioState Apr 12 08:36:19 volumio volumio[955]: info: CoreStateMachine::getcurrentVolume Apr 12 08:36:19 volumio volumio[955]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 08:36:19 volumio volumio[955]: info: Volumio Network Manager: Network status updated: 1 Apr 12 08:36:19 volumio volumio[955]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 12 08:36:19 volumio volumio[955]: wlan0 Interface doesn't support scanning : Operation not supported Apr 12 08:36:19 volumio volumio[955]: info: Cannot use regular scanning, forcing with ap-force Apr 12 08:36:19 volumio sudo[1201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 12 08:36:19 volumio sudo[1201]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:20 volumio sudo[1201]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:20 volumio volumio[955]: Unable to parse: Apr 12 08:36:20 volumio volumio[955]: Simple mixer control 'Master',0 Apr 12 08:36:20 volumio volumio[955]: Capabilities: volume volume-joined Apr 12 08:36:20 volumio volumio[955]: Playback channels: Mono Apr 12 08:36:20 volumio volumio[955]: Capture channels: Mono Apr 12 08:36:20 volumio volumio[955]: Limits: 0 - 248 Apr 12 08:36:20 volumio volumio[955]: Mono: 248 [100%] Apr 12 08:36:20 volumio volumio[955]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Apr 12 08:36:20 volumio volumio[955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 12 08:36:20 volumio volumio[955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:20 volumio volumio[955]: info: Reloading queue from file Apr 12 08:36:20 volumio volumio[955]: Unable to parse: Apr 12 08:36:20 volumio volumio[955]: Simple mixer control 'Master',0 Apr 12 08:36:20 volumio volumio[955]: Capabilities: volume volume-joined Apr 12 08:36:20 volumio volumio[955]: Playback channels: Mono Apr 12 08:36:20 volumio volumio[955]: Capture channels: Mono Apr 12 08:36:20 volumio volumio[955]: Limits: 0 - 248 Apr 12 08:36:20 volumio volumio[955]: Mono: 248 [100%] Apr 12 08:36:20 volumio volumio[955]: info: VolumeController:: Volume=undefined Mute =false Apr 12 08:36:20 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:20 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:20 volumio volumio[955]: info: CoreStateMachine::updateTrackBlock Apr 12 08:36:20 volumio volumio[955]: info: CorePlayQueue::getTrackBlock Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 08:36:20 volumio volumio[955]: info: CoreStateMachine::setRepeat true single undefined Apr 12 08:36:20 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:20 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:20 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:20 volumio volumio[955]: info: Setting Device type: Raspberry PI Apr 12 08:36:20 volumio volumio[955]: info: Completed loading Core Plugins Apr 12 08:36:20 volumio volumio[955]: info: Preparing to generate the ALSA configuration file Apr 12 08:36:20 volumio volumio[955]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 12 08:36:20 volumio volumio[955]: Unable to parse: Apr 12 08:36:20 volumio volumio[955]: Simple mixer control 'Master',0 Apr 12 08:36:20 volumio volumio[955]: Capabilities: volume volume-joined Apr 12 08:36:20 volumio volumio[955]: Playback channels: Mono Apr 12 08:36:20 volumio volumio[955]: Capture channels: Mono Apr 12 08:36:20 volumio volumio[955]: Limits: 0 - 248 Apr 12 08:36:20 volumio volumio[955]: Mono: 248 [100%] Apr 12 08:36:20 volumio volumio[955]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Apr 12 08:36:20 volumio volumio[955]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Apr 12 08:36:20 volumio volumio[955]: info: Reading ALSA contributions from plugins. Apr 12 08:36:20 volumio volumio[955]: Unable to parse: Apr 12 08:36:20 volumio volumio[955]: Simple mixer control 'Master',0 Apr 12 08:36:20 volumio volumio[955]: Capabilities: volume volume-joined Apr 12 08:36:20 volumio volumio[955]: Playback channels: Mono Apr 12 08:36:20 volumio volumio[955]: Capture channels: Mono Apr 12 08:36:20 volumio volumio[955]: Limits: 0 - 248 Apr 12 08:36:20 volumio volumio[955]: Mono: 248 [100%] Apr 12 08:36:20 volumio volumio[955]: info: VolumeController:: Volume=undefined Mute =false Apr 12 08:36:20 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:20 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:20 volumio volumio[955]: info: Discovery: adding 82d6564b-839f-4e8c-aa78-23d910638f36 Apr 12 08:36:20 volumio volumio[955]: info: Discovery: Found device Volumio Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:20 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:20 volumio volumio[955]: info: Discovery: this is already registered, 82d6564b-839f-4e8c-aa78-23d910638f36 Apr 12 08:36:20 volumio volumio[955]: info: Discovery: Found device Volumio Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:20 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:20 volumio volumio[955]: info: Asound.conf file unchanged, so no further update is needed Apr 12 08:36:20 volumio volumio[955]: info: Output device has changed, restarting MPD Apr 12 08:36:20 volumio volumio[955]: info: Output device has changed, restarting Shairport Sync Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:20 volumio sudo[1213]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 08:36:20 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:20 volumio sudo[1213]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:20 volumio sudo[1213]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:20 volumio sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 08:36:20 volumio sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio volumio[955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 08:36:21 volumio volumio[955]: info: ___________ START PLUGINS ___________ Apr 12 08:36:21 volumio systemd[1]: Listening on mpd.socket. Apr 12 08:36:21 volumio systemd[1]: Starting Music Player Daemon... Apr 12 08:36:21 volumio volumio[955]: info: ControllerMpd::onStart: Initializing MPD Apr 12 08:36:21 volumio volumio[955]: info: Creating MPD Configuration file Apr 12 08:36:21 volumio sudo[1235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 12 08:36:21 volumio sudo[1235]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio sudo[1239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 08:36:21 volumio volumio[955]: info: [1775975781146] CoreMusicLibrary::Adding element Serveurs Média Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:21 volumio sudo[1239]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio systemd[1]: Started Volumio5 Onboarding Server. Apr 12 08:36:21 volumio sudo[1235]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:21 volumio sudo[1239]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:21 volumio sudo[1241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 08:36:21 volumio volumio[955]: info: UPNP Browser: Client initialized successfully Apr 12 08:36:21 volumio sudo[1241]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:21 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Apr 12 08:36:21 volumio systemd[1]: mpd.service: Succeeded. Apr 12 08:36:21 volumio systemd[1]: Stopped Music Player Daemon. Apr 12 08:36:21 volumio volumio[955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:21 volumio systemd[1]: Starting Music Player Daemon... Apr 12 08:36:21 volumio volumio[955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 08:36:21 volumio volumio[955]: info: [1775975781312] CoreMusicLibrary::Adding element Last_100 Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 08:36:21 volumio volumio[955]: info: [1775975781317] CoreMusicLibrary::Adding element Webradio Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:36:21 volumio volumio[955]: info: Initializing BBC Radios Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:21 volumio volumio[955]: info: AutoStart - onStart Apr 12 08:36:21 volumio sudo[1250]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 08:36:21 volumio sudo[1250]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio sudo[1250]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 12 08:36:21 volumio sudo[1250]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:21 volumio volumio[955]: info: [now-playing] ConfigUpdater: config is up to date. Apr 12 08:36:21 volumio volumio[955]: info: Loading i18n strings for locale fr Apr 12 08:36:21 volumio volumio[955]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:21 volumio volumio[955]: info: FusionDsp - mixtype--------------------- Hardware Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 08:36:21 volumio volumio[955]: info: [1775975781481] CoreMusicLibrary::Adding element 80s80s Radio Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:21 volumio volumio[955]: Cannot find translation for source 80s80s Radio Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 12 08:36:21 volumio volumio[955]: info: [MPD_OLED Plugin] Not starting mpd_oled service because oled type is not configured yet Apr 12 08:36:21 volumio fsct-plugin[955]: Starting service tasks Apr 12 08:36:21 volumio fsct-plugin[955]: Service tasks started successfully Apr 12 08:36:21 volumio fsct-plugin[955]: Failed to initialize device 7392:7811: BOS descriptor not available, unsupported usb version 2.00 Apr 12 08:36:21 volumio fsct-plugin[955]: Failed to initialize device 1d6b:0002: BOS descriptor not available, unsupported usb version 2.00 Apr 12 08:36:21 volumio fsct-plugin[955]: Failed to initialize device 0424:2514: BOS descriptor not available, unsupported usb version 2.00 Apr 12 08:36:21 volumio fsct-plugin[955]: Failed to initialize device 0424:2514: BOS descriptor not available, unsupported usb version 2.00 Apr 12 08:36:21 volumio fsct-plugin[955]: Failed to initialize device 0424:7800: IO error -> Permission denied (os error 13) Apr 12 08:36:21 volumio volumio[955]: info: Loading i18n strings for locale fr Apr 12 08:36:21 volumio volumio[955]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:36:21 volumio volumio[955]: info: Volumio Calling Home Apr 12 08:36:21 volumio volumio[955]: info: Preparing to generate the ALSA configuration file Apr 12 08:36:21 volumio sudo[1290]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Apr 12 08:36:21 volumio sudo[1290]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio sudo[1292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Apr 12 08:36:21 volumio sudo[1292]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio volumio5-onboarding[1242]: time=2026-04-12T08:36:21.781+02:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 12 08:36:21 volumio sudo[1295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Apr 12 08:36:21 volumio sudo[1295]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio volumio[955]: info: [now-playing] App is listening on port 4004. Apr 12 08:36:21 volumio volumio[955]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Apr 12 08:36:21 volumio systemd[1]: Reloading. Apr 12 08:36:21 volumio volumio[955]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 12 08:36:21 volumio volumio[955]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Apr 12 08:36:21 volumio volumio[955]: info: Reading ALSA contributions from plugins. Apr 12 08:36:21 volumio volumio[955]: info: touch_display: Backlight interface detected. Apr 12 08:36:21 volumio sudo[1301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 08:36:21 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:21 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:21 volumio sudo[1303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 08:36:21 volumio sudo[1303]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:21 volumio sudo[1301]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio sudo[1303]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:22 volumio sudo[1301]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:22 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: na Apr 12 08:36:22 volumio volumio[955]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 12 08:36:22 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: na Apr 12 08:36:22 volumio volumio[955]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 12 08:36:22 volumio volumio[955]: info: MPD Permissions set Apr 12 08:36:22 volumio volumio[955]: info: MPD Permissions set Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:22 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:22 volumio volumio[955]: info: FSCT Started Apr 12 08:36:22 volumio volumio[955]: 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: 3 Apr 12 08:36:22 volumio volumio[955]: info: Volumio called home Apr 12 08:36:22 volumio volumio[955]: 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: 3 Apr 12 08:36:22 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:22 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:22 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:22 volumio volumio5-onboarding[1242]: time=2026-04-12T08:36:22.286+02:00 level=INFO msg="system info for 1d09f5c2b4173ab806b46b684d6f3f0a" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=3.912 Apr 12 08:36:22 volumio volumio[955]: 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 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 12 08:36:22 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:22 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:22 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 08:36:22 volumio volumio5-onboarding[1242]: time=2026-04-12T08:36:22.477+02:00 level=INFO msg="enabling local network discovery" Apr 12 08:36:22 volumio volumio5-onboarding[1242]: time=2026-04-12T08:36:22.501+02:00 level=INFO msg="enabling BLE discovery" Apr 12 08:36:22 volumio volumio[955]: info: touch_display: Raspberry Pi Foundation touch screen detected. Apr 12 08:36:22 volumio volumio[955]: info: Starting Shairport Sync Apr 12 08:36:22 volumio sudo[1333]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Apr 12 08:36:22 volumio bluetoothd[743]: src/adapter.c:store_adapter_info() Unable set contents for /usr/var/lib/bluetooth/B8:27:EB:44:77:98/settings: (Failed to create file “/usr/var/lib/bluetooth/B8:27:EB:44:77:98/settings.UQZCN3”: No such file or directory) Apr 12 08:36:22 volumio sudo[1333]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio volumio[955]: info: Starting Shairport Sync Apr 12 08:36:22 volumio volumio5-onboarding[1242]: time=2026-04-12T08:36:22.581+02:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 12 08:36:22 volumio sudo[1335]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Apr 12 08:36:22 volumio sudo[1335]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio sudo[1335]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:22 volumio volumio[955]: info: Starting Shairport Sync Apr 12 08:36:22 volumio sudo[1338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 08:36:22 volumio sudo[1338]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio sudo[1341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 08:36:22 volumio sudo[1341]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:22 volumio sudo[1333]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:22 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:22 volumio sudo[1344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 08:36:22 volumio sudo[1344]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:22 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:22 volumio sudo[1349]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 12 08:36:22 volumio sudo[1349]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:22 volumio volumio[955]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Apr 12 08:36:22 volumio volumio[955]: info: touch_display: File permissions for backlight brightness control set. Apr 12 08:36:22 volumio volumio[955]: info: [ASDebug] Togle GPIO: OFF Apr 12 08:36:22 volumio volumio[955]: info: Asound.conf file unchanged, so no further update is needed Apr 12 08:36:22 volumio volumio[955]: info: Output device has changed, restarting MPD Apr 12 08:36:22 volumio volumio[955]: info: Output device has changed, restarting Shairport Sync Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:22 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:22 volumio sudo[1353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 08:36:22 volumio sudo[1353]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio sudo[1355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 08:36:22 volumio sudo[1355]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:22 volumio sudo[1353]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:22 volumio volumio[955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 08:36:22 volumio volumio[955]: info: Preparing to generate the ALSA configuration file Apr 12 08:36:23 volumio systemd[1]: Reloading. Apr 12 08:36:23 volumio sudo[1292]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:23 volumio sudo[1362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 08:36:23 volumio sudo[1362]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:23 volumio sudo[1362]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:23 volumio sudo[1364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 08:36:23 volumio sudo[1364]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:23 volumio sudo[1364]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:23 volumio volumio[955]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 12 08:36:23 volumio volumio[955]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Apr 12 08:36:23 volumio volumio[955]: info: Reading ALSA contributions from plugins. Apr 12 08:36:23 volumio volumio[955]: info: MPD Permissions set Apr 12 08:36:23 volumio volumio[955]: info: touch_display: systemctl disable getty@tty1.service succeeded. Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: Starting Shairport Sync Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:23 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::volumioPause Apr 12 08:36:23 volumio volumio[955]: info: CoreStateMachine::pause Apr 12 08:36:23 volumio volumio[955]: info: mpdhttpout --- Volumio set on pause Apr 12 08:36:23 volumio volumio[955]: info: mpdhttpout ---Configuration successfully added to mpd.conf. Apr 12 08:36:23 volumio volumio[955]: info: Asound.conf file unchanged, so no further update is needed Apr 12 08:36:23 volumio volumio[955]: info: Output device has changed, restarting MPD Apr 12 08:36:23 volumio sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 08:36:23 volumio sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:23 volumio sudo[1388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 08:36:23 volumio sudo[1388]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:23 volumio sudo[1388]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:23 volumio volumio[955]: info: Output device has changed, restarting Shairport Sync Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:23 volumio sudo[1392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 08:36:23 volumio sudo[1392]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:23 volumio volumio[955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 08:36:23 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 12 08:36:23 volumio volumio[955]: info: camilladsp service started and running in background, instance 1 Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 <-AAAAAAAAAAAAA Apr 12 08:36:23 volumio volumio[955]: info: FusionDsp loaded Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:23 volumio sudo[1407]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Apr 12 08:36:23 volumio sudo[1407]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:23 volumio volumio[955]: info: FusionDsp - Reporting Fusion DSP Enabled Apr 12 08:36:23 volumio volumio[955]: info: Adding Signal Path Element [object Object] Apr 12 08:36:23 volumio volumio[955]: info: Adding fusiondspeq DSP Signal Path Element Apr 12 08:36:23 volumio volumio[955]: info: FusionDsp - ---- installed callbackRead Apr 12 08:36:23 volumio volumio[955]: info: MPD Permissions set Apr 12 08:36:23 volumio volumio[955]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 12 08:36:23 volumio volumio[955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 12 08:36:23 volumio volumio[955]: error: FusionDsp - WebSocket error: [object Object] Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:23 volumio volumio[955]: info: Starting Shairport Sync Apr 12 08:36:23 volumio volumio[955]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:23 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:23 volumio volumio[955]: info: CoreCommandRouter::volumioPause Apr 12 08:36:23 volumio volumio[955]: info: CoreStateMachine::pause Apr 12 08:36:23 volumio volumio[955]: info: mpdhttpout --- Volumio set on pause Apr 12 08:36:23 volumio sudo[1416]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 08:36:23 volumio sudo[1416]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:23 volumio volumio-remote-updater[551]: [2026-04-12 08:36:23] [connect] Successful connection Apr 12 08:36:23 volumio volumio-remote-updater[551]: [2026-04-12 08:36:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1775975783 101 Apr 12 08:36:23 volumio volumio[955]: 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: 6 Apr 12 08:36:23 volumio systemd[1]: systemd-fsckd.service: Succeeded. Apr 12 08:36:23 volumio sudo[1295]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio volumio[955]: info: touch_display: systemctl daemon-reload succeeded. Apr 12 08:36:24 volumio volumio[955]: verbose: New Socket.io Connection to 192.168.1.253 from 192.168.1.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Edg/146.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Apr 12 08:36:24 volumio sudo[1419]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Apr 12 08:36:24 volumio sudo[1419]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:24 volumio systemd[1]: Started Volumio Kiosk. Apr 12 08:36:24 volumio systemd[1]: Started FusionDsp Daemon. Apr 12 08:36:24 volumio sudo[1407]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 12 08:36:24 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 12 08:36:24 volumio sudo[1349]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio volumio[955]: info: Upmpdcli Daemon Started Apr 12 08:36:24 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 12 08:36:24 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 12 08:36:24 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 12 08:36:24 volumio systemd[1]: mpd.service: Succeeded. Apr 12 08:36:24 volumio systemd[1]: Stopped Music Player Daemon. Apr 12 08:36:24 volumio sudo[1419]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1290]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 08:36:24 volumio volumio[955]: info: touch_display: systemctl stop getty@tty1.service succeeded. Apr 12 08:36:24 volumio volumio[955]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Apr 12 08:36:24 volumio volumio[955]: info: touch_display: Volumio Kiosk started. Apr 12 08:36:24 volumio sudo[1445]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:24 volumio sudo[1445]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1449]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 08:36:24 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:24 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:24 volumio sudo[1449]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:24 volumio systemd[1]: Starting Music Player Daemon... Apr 12 08:36:24 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 12 08:36:24 volumio sudo[1386]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1449]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1341]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1338]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1344]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio sudo[1416]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:24 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:24 volumio volumio[955]: info: Shairport-Sync Started Apr 12 08:36:24 volumio volumio[955]: Error adding Membership: Error: addMembership EINVAL Apr 12 08:36:24 volumio startx[1421]: X.Org X Server 1.20.4 Apr 12 08:36:24 volumio startx[1421]: X Protocol Version 11, Revision 0 Apr 12 08:36:24 volumio startx[1421]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Apr 12 08:36:24 volumio startx[1421]: Current Operating System: Linux volumio 6.6.62-v7+ #1816 SMP Mon Nov 18 15:30:49 GMT 2024 armv7l Apr 12 08:36:24 volumio startx[1421]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=ad719006-1b2d-490d-8a3a-2bcff9c8a716 imgfile=/volumio_current.sqsh bootpart=UUID=12EB-C1B6 datapart=UUID=1181d16e-f23e-4d2c-a1b2-9ca3d0380f61 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Apr 12 08:36:24 volumio startx[1421]: Build Date: 04 April 2023 07:50:56AM Apr 12 08:36:24 volumio startx[1421]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Apr 12 08:36:24 volumio startx[1421]: Current version of pixman: 0.36.0 Apr 12 08:36:24 volumio startx[1421]: Before reporting problems, check http://wiki.x.org Apr 12 08:36:24 volumio startx[1421]: to make sure that you have the latest version. Apr 12 08:36:24 volumio startx[1421]: Markers: (--) probed, (**) from config file, (==) default setting, Apr 12 08:36:24 volumio startx[1421]: (++) from command line, (!!) notice, (II) informational, Apr 12 08:36:24 volumio startx[1421]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Apr 12 08:36:24 volumio startx[1421]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Apr 12 08:36:24 2026 Apr 12 08:36:24 volumio volumio[955]: info: Shairport-Sync Started Apr 12 08:36:24 volumio volumio[955]: info: Shairport-Sync Started Apr 12 08:36:24 volumio volumio[955]: info: Shairport-Sync Started Apr 12 08:36:24 volumio startx[1421]: (==) Using config directory: "/etc/X11/xorg.conf.d" Apr 12 08:36:24 volumio startx[1421]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Apr 12 08:36:24 volumio volumio[955]: info: Shairport-Sync Started Apr 12 08:36:24 volumio sudo[1446]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 08:36:24 volumio sudo[1446]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:24 volumio volumio[955]: info: touch_display: X display number found: 0 Apr 12 08:36:24 volumio sudo[1446]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 12 08:36:24 volumio sudo[1446]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:24 volumio volumio[955]: verbose: New Socket.io Connection to 192.168.1.253 from 192.168.1.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Edg/146.0.0.0 Engine version: 3 Transport: polling Total Clients: 8 Apr 12 08:36:24 volumio volumio[955]: 0+0 records in Apr 12 08:36:24 volumio volumio[955]: 0+0 records out Apr 12 08:36:24 volumio volumio[955]: 0 bytes copied, 0.000127083 s, 0.0 kB/s Apr 12 08:36:24 volumio volumio[955]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 12 08:36:24 volumio volumio[955]: info: touch_display: X display number found: 0 Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:25 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:25 volumio volumio[955]: info: Listing playlists Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Apr 12 08:36:25 volumio sudo[1470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 08:36:25 volumio sudo[1470]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:25 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 12 08:36:25 volumio systemd[1]: mpd.service: Succeeded. Apr 12 08:36:25 volumio systemd[1]: Stopped Music Player Daemon. Apr 12 08:36:25 volumio systemd[1]: Starting Music Player Daemon... Apr 12 08:36:25 volumio sudo[1472]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 08:36:25 volumio sudo[1472]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:25 volumio sudo[1472]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 12 08:36:25 volumio sudo[1472]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:25 volumio volumio[955]: 0+0 records in Apr 12 08:36:25 volumio volumio[955]: 0+0 records out Apr 12 08:36:25 volumio volumio[955]: 0 bytes copied, 0.000167812 s, 0.0 kB/s Apr 12 08:36:25 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Apr 12 08:36:25 volumio sudo[1481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 08:36:25 volumio sudo[1481]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:25 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 12 08:36:25 volumio systemd[1]: mpd.service: Succeeded. Apr 12 08:36:25 volumio systemd[1]: Stopped Music Player Daemon. Apr 12 08:36:26 volumio systemd[1]: Starting Music Player Daemon... Apr 12 08:36:26 volumio sudo[1483]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 08:36:26 volumio sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:26 volumio sudo[1483]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 12 08:36:26 volumio sudo[1483]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:26 volumio volumio[955]: info: VolumeController::SetAlsaVolume0 Apr 12 08:36:26 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:26 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:26 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:36:26 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:26 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: stop Apr 12 08:36:26 volumio volumio[955]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 12 08:36:26 volumio volumio[955]: 0+0 records in Apr 12 08:36:26 volumio volumio[955]: 0+0 records out Apr 12 08:36:26 volumio volumio[955]: 0 bytes copied, 0.000613698 s, 0.0 kB/s Apr 12 08:36:27 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:27 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:27 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:27 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:27 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:27 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:27 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:27 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:27 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 12 08:36:27 volumio volumio[955]: 0+0 records in Apr 12 08:36:27 volumio volumio[955]: 0+0 records out Apr 12 08:36:27 volumio volumio[955]: 0 bytes copied, 0.00013375 s, 0.0 kB/s Apr 12 08:36:28 volumio mpd[1493]: Apr 12 08:36 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 12 08:36:28 volumio systemd[1]: Started Music Player Daemon. Apr 12 08:36:28 volumio volumio[955]: Upnp client error: Error: This socket has been ended by the other party Apr 12 08:36:28 volumio sudo[1481]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:28 volumio sudo[1215]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:28 volumio sudo[1470]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:28 volumio sudo[1392]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:28 volumio sudo[1355]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:28 volumio sudo[1241]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:28 volumio volumio[955]: info: Completed starting Core Plugins Apr 12 08:36:28 volumio volumio[955]: info: ------------------------------------------- Apr 12 08:36:28 volumio volumio[955]: info: ----- MyVolumio plugins startup ---- Apr 12 08:36:28 volumio volumio[955]: info: ------------------------------------------- Apr 12 08:36:28 volumio volumio[955]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 12 08:36:28 volumio volumio[955]: error: MPD error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: MPD error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: MPD error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: MPD error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: MPD error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: error: The expression evaluated to a falsy value: Apr 12 08:36:28 volumio volumio[955]: assert.ok(self.idling) Apr 12 08:36:28 volumio volumio[955]: info: MPD running with PID1493 Apr 12 08:36:28 volumio volumio[955]: ,establishing connection Apr 12 08:36:28 volumio volumio[955]: error: updateQueue error: null Apr 12 08:36:28 volumio volumio[955]: error: updateQueue error: null Apr 12 08:36:28 volumio volumio[1428]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 12 08:36:28 volumio volumio[955]: 0+0 records in Apr 12 08:36:28 volumio volumio[955]: 0+0 records out Apr 12 08:36:28 volumio volumio[955]: 0 bytes copied, 0.000158698 s, 0.0 kB/s Apr 12 08:36:30 volumio volumio[955]: 0+0 records in Apr 12 08:36:30 volumio volumio[955]: 0+0 records out Apr 12 08:36:30 volumio volumio[955]: 0 bytes copied, 0.000131875 s, 0.0 kB/s Apr 12 08:36:31 volumio volumio[955]: 0+0 records in Apr 12 08:36:31 volumio volumio[955]: 0+0 records out Apr 12 08:36:31 volumio volumio[955]: 0 bytes copied, 0.000197917 s, 0.0 kB/s Apr 12 08:36:32 volumio volumio[955]: 0+0 records in Apr 12 08:36:32 volumio volumio[955]: 0+0 records out Apr 12 08:36:32 volumio volumio[955]: 0 bytes copied, 0.000143541 s, 0.0 kB/s Apr 12 08:36:33 volumio volumio[955]: 0+0 records in Apr 12 08:36:33 volumio volumio[955]: 0+0 records out Apr 12 08:36:33 volumio volumio[955]: 0 bytes copied, 0.000153021 s, 0.0 kB/s Apr 12 08:36:33 volumio volumio[955]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 12 08:36:34 volumio volumio[955]: 0+0 records in Apr 12 08:36:34 volumio volumio[955]: 0+0 records out Apr 12 08:36:34 volumio volumio[955]: 0 bytes copied, 0.000141406 s, 0.0 kB/s Apr 12 08:36:35 volumio volumio[955]: 0+0 records in Apr 12 08:36:35 volumio volumio[955]: 0+0 records out Apr 12 08:36:35 volumio volumio[955]: 0 bytes copied, 0.000127031 s, 0.0 kB/s Apr 12 08:36:36 volumio volumio[955]: 0+0 records in Apr 12 08:36:36 volumio volumio[955]: 0+0 records out Apr 12 08:36:36 volumio volumio[955]: 0 bytes copied, 0.000120573 s, 0.0 kB/s Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 12 08:36:36 volumio volumio[955]: info: Adding plugin bluetooth to MyMusic Plugins Apr 12 08:36:36 volumio volumio[955]: info: Adding plugin multiroom to MyMusic Plugins Apr 12 08:36:36 volumio volumio[955]: info: Adding plugin metavolumio to MyMusic Plugins Apr 12 08:36:36 volumio volumio[955]: info: Adding plugin cd_controller to MyMusic Plugins Apr 12 08:36:36 volumio volumio[955]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 12 08:36:36 volumio volumio[955]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 12 08:36:36 volumio volumio[955]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 12 08:36:36 volumio volumio[955]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 12 08:36:37 volumio systemd[1]: systemd-timedated.service: Succeeded. Apr 12 08:36:38 volumio volumio[955]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 12 08:36:38 volumio volumio[955]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 12 08:36:38 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:38 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:38 volumio volumio[955]: info: Starting MyVolumio Remote Streaming Endpoints Apr 12 08:36:38 volumio volumio[955]: info: MyVolumio login type: Token Apr 12 08:36:38 volumio volumio[955]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 12 08:36:38 volumio volumio[955]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 12 08:36:39 volumio volumio[955]: info: Starting Streaming Service Transparent Proxy Apr 12 08:36:39 volumio volumio[955]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 12 08:36:39 volumio volumio[955]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 12 08:36:39 volumio volumio[955]: info: Streaming services startup Apr 12 08:36:39 volumio volumio[955]: info: Starting Streaming Daemon Apr 12 08:36:40 volumio volumio[955]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 12 08:36:40 volumio sudo[1757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 12 08:36:40 volumio sudo[1757]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:40 volumio sudo[1757]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:40 volumio volumio[955]: 0+0 records in Apr 12 08:36:40 volumio volumio[955]: 0+0 records out Apr 12 08:36:40 volumio volumio[955]: 0 bytes copied, 0.00013401 s, 0.0 kB/s Apr 12 08:36:40 volumio volumio[955]: error: Cannot start Volumio Streaming Daemon Apr 12 08:36:40 volumio volumio[955]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 12 08:36:40 volumio volumio[955]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 12 08:36:40 volumio volumio[955]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 12 08:36:41 volumio volumio[955]: 0+0 records in Apr 12 08:36:41 volumio volumio[955]: 0+0 records out Apr 12 08:36:41 volumio volumio[955]: 0 bytes copied, 0.000163125 s, 0.0 kB/s Apr 12 08:36:41 volumio volumio[955]: info: MyVolumio token set successfully Apr 12 08:36:41 volumio volumio[955]: info: MYVOLUMIO: Adding device Apr 12 08:36:41 volumio volumio[955]: info: MYVOLUMIO: Evaluating Server Apr 12 08:36:41 volumio volumio[955]: info: AutoStart - Plugin is starting Apr 12 08:36:41 volumio volumio[955]: info: CoreCommandRouter::volumioGetQueue Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::getQueue Apr 12 08:36:41 volumio volumio[955]: info: CorePlayQueue::getQueue Apr 12 08:36:41 volumio volumio[955]: info: AutoStart - start playing Apr 12 08:36:41 volumio volumio[955]: info: AutoStart - start playing with no specific position Apr 12 08:36:41 volumio volumio[955]: info: CoreCommandRouter::volumioPlay Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::play index 0 Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::stop Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::play index undefined Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 08:36:41 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:41 volumio volumio[955]: info: CoreStateMachine::startPlaybackTimer Apr 12 08:36:41 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:41 volumio volumio[955]: info: [1775975801912] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/grunge/mp3-192/volumio Apr 12 08:36:41 volumio volumio[955]: info: [1775975801913] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=253&count=2 Apr 12 08:36:41 volumio volumio[955]: info: MyVolumio status changed Apr 12 08:36:41 volumio volumio[955]: info: Streaming services startup Apr 12 08:36:41 volumio volumio[955]: info: Starting Streaming Daemon Apr 12 08:36:41 volumio volumio[955]: info: Removing browser output: myVolumio user plan is not superstar Apr 12 08:36:41 volumio volumio[955]: info: Removing audio output: Apr 12 08:36:41 volumio volumio[955]: info: Stoppping Tunnel 1 Apr 12 08:36:41 volumio sudo[1814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 12 08:36:41 volumio sudo[1814]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:42 volumio sudo[1814]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:42 volumio sudo[1816]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 12 08:36:42 volumio sudo[1816]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:36:42 volumio volumio[955]: error: Cannot start Volumio Streaming Daemon Apr 12 08:36:42 volumio volumio[955]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 12 08:36:42 volumio volumio[955]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 12 08:36:42 volumio volumio[955]: STREAMING PROXY: Starting server on port 3245 Apr 12 08:36:42 volumio volumio[955]: Node JS runtime: 14 Apr 12 08:36:42 volumio sudo[1816]: pam_unix(sudo:session): session closed for user root Apr 12 08:36:42 volumio volumio[955]: info: Remote SSH Stopped Apr 12 08:36:42 volumio volumio[955]: info: Setting Geolocation for MyVolumio to eu2 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:42 volumio volumio[955]: info: [1775975802190] [80s80s] received new event containing 2 songs. Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand stop took 6 milliseconds Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand clear took 16 milliseconds Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand consume 1 Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: error: updateQueue error: null Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces state update: options Apr 12 08:36:42 volumio volumio[955]: error: updateQueue error: null Apr 12 08:36:42 volumio volumio[955]: error: updateQueue error: null Apr 12 08:36:42 volumio volumio[955]: error: updateQueue error: null Apr 12 08:36:42 volumio volumio[955]: error: updateQueue error: null Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 43ms Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand consume 1 took 36 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 36ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 33ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 31ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 25ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 21ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 18ms Apr 12 08:36:42 volumio volumio[955]: info: [1775975802262] [80s80s] adding url: http://streams.90s90s.de/grunge/mp3-192/volumio Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/grunge/mp3-192/volumio" Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces state update: options Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces state update: options Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces state update: options Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces state update: options Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces state update: options Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces state update: options Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:42 volumio volumio[955]: 0+0 records in Apr 12 08:36:42 volumio volumio[955]: 0+0 records out Apr 12 08:36:42 volumio volumio[955]: 0 bytes copied, 0.000148854 s, 0.0 kB/s Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand status took 101 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand add "http://streams.90s90s.de/grunge/mp3-192/volumio" took 98 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand status took 95 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand status took 92 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand status took 91 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand status took 88 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand status took 85 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand status took 84 milliseconds Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand play Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:42 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:42 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 179ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 242ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 238ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 236ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 235ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 232ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 230ms Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: Apr 12 08:36:42 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:42 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 174ms Apr 12 08:36:42 volumio volumio[955]: info: sendMpdCommand play took 158 milliseconds Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 24ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 23ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 22ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 21ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 21ms Apr 12 08:36:42 volumio volumio[955]: info: ------------------------------ 20ms Apr 12 08:36:42 volumio volumio[955]: info: [1775975802537] [80s80s] Pushing the next song state: Nirvana - About a Girl Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music115/v4/6b/80/82/6b808262-1f95-a926-3d2d-ac71fc0b675a/source/600x600bb.jpg","name":"Nirvana - About a Girl","title":"About a Girl","artist":"90s90s Grunge","album":"","streaming":true,"disableUiControls":true,"duration":"176","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Apr 12 08:36:42 volumio volumio[955]: verbose: CURRENT POSITION 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::syncState stateService play Apr 12 08:36:42 volumio volumio[955]: info: CoreStateMachine::syncState currentStatus stop Apr 12 08:36:42 volumio volumio[955]: info: [1775975802544] [80s80s] PlayNextTrack API delay: 30 Apr 12 08:36:42 volumio volumio[955]: info: [1775975802565] [80s80s] Setting timer to: 176000 milliseconds. Apr 12 08:36:42 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: stop Apr 12 08:36:42 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: stop Apr 12 08:36:42 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: stop Apr 12 08:36:42 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: stop Apr 12 08:36:42 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: stop Apr 12 08:36:42 volumio volumio[955]: info: [ASDebug] CurState: stop PrevState: stop Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 08:36:42 volumio volumio[955]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 12 08:36:42 volumio volumio[955]: info: Received Get System Version Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:36:42 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:42 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:42 volumio volumio[955]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 12 08:36:43 volumio volumio[955]: info: Updating MyVolumio device info Apr 12 08:36:43 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:43 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:43 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:43 volumio volumio[955]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Apr 12 08:36:43 volumio volumio[955]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 12 08:36:43 volumio volumio[955]: 0+0 records in Apr 12 08:36:43 volumio volumio[955]: 0+0 records out Apr 12 08:36:43 volumio volumio[955]: 0 bytes copied, 0.000144583 s, 0.0 kB/s Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Apr 12 08:36:44 volumio volumio[955]: info: FusionDsp - ---- read samplerate from file: 44100 Apr 12 08:36:44 volumio volumio[955]: info: camilladsp service terminated, instance 1 Apr 12 08:36:44 volumio volumio[955]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 12 08:36:44 volumio volumio[955]: info: camilladsp service started and running in background, instance 1 Apr 12 08:36:44 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:44 volumio volumio[955]: 22+1 records in Apr 12 08:36:44 volumio volumio[955]: 22+1 records out Apr 12 08:36:44 volumio volumio[955]: 746560 bytes (747 kB, 729 KiB) copied, 0.0170284 s, 43.8 MB/s Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:44 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 166 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 167 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 166 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 165 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 159 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 135 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 132 milliseconds Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:44 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:44 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:44 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:44 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:44 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces system playlist update Apr 12 08:36:44 volumio volumio[955]: info: Ignoring MPD Status Update Apr 12 08:36:44 volumio volumio[955]: info: Apr 12 08:36:44 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 74ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 68 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 66 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 64 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 64 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 62 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 61 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 60 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 57ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 54 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 51ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 43 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 43ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 41 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 39ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 42 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 42ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 41 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 39ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand status took 31 milliseconds Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 282ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 279ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 278ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 277ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 270ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 246ms Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 34 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 27 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 28 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 28 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 27 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 28 milliseconds Apr 12 08:36:44 volumio volumio[955]: info: sendMpdCommand playlistinfo took 27 milliseconds Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 150ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 127ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 119ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 111ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 107ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 104ms Apr 12 08:36:44 volumio volumio[955]: info: ------------------------------ 99ms Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:44 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 08:36:44 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 08:36:45 volumio volumio[955]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Apr 12 08:36:45 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:45 volumio volumio[955]: 2+0 records in Apr 12 08:36:45 volumio volumio[955]: 2+0 records out Apr 12 08:36:45 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000473438 s, 138 MB/s Apr 12 08:36:46 volumio volumio[1428]: .....................................................................................................................................................++++ Apr 12 08:36:46 volumio volumio[955]: info: MYVOLUMIO: Adding device Apr 12 08:36:46 volumio volumio[955]: info: MYVOLUMIO: Evaluating Server Apr 12 08:36:46 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:46 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:46 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:46 volumio volumio[955]: 2+0 records in Apr 12 08:36:46 volumio volumio[955]: 2+0 records out Apr 12 08:36:46 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000636667 s, 103 MB/s Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 08:36:47 volumio volumio[955]: info: Listing playlists Apr 12 08:36:47 volumio volumio[955]: info: Setting Geolocation for MyVolumio to eu5 Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 08:36:47 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 08:36:47 volumio volumio[955]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 12 08:36:48 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:48 volumio volumio[955]: 1+1 records in Apr 12 08:36:48 volumio volumio[955]: 1+1 records out Apr 12 08:36:48 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.00126453 s, 48.8 MB/s Apr 12 08:36:48 volumio volumio[955]: info: Updating MyVolumio device info Apr 12 08:36:48 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:48 volumio volumio[955]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 12 08:36:49 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:49 volumio volumio[955]: 2+0 records in Apr 12 08:36:49 volumio volumio[955]: 2+0 records out Apr 12 08:36:49 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000496771 s, 132 MB/s Apr 12 08:36:50 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:50 volumio volumio[955]: 1+1 records in Apr 12 08:36:50 volumio volumio[955]: 1+1 records out Apr 12 08:36:50 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.00056625 s, 109 MB/s Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:51 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:51 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:51 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 12 08:36:51 volumio volumio-remote-updater[551]: No test mode Apr 12 08:36:51 volumio volumio-remote-updater[551]: No alpha test mode Apr 12 08:36:51 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:51 volumio volumio[955]: 2+0 records in Apr 12 08:36:51 volumio volumio[955]: 2+0 records out Apr 12 08:36:51 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000513021 s, 128 MB/s Apr 12 08:36:51 volumio volumio[955]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:51 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 12 08:36:52 volumio volumio[955]: info: CoreCommandRouter::volumioPlay Apr 12 08:36:52 volumio volumio[955]: info: CoreStateMachine::play index undefined Apr 12 08:36:52 volumio volumio[955]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 08:36:52 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:52 volumio volumio5-onboarding[1242]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Apr 12 08:36:52 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 12 08:36:52 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 12 08:36:52 volumio systemd[1]: volumio5-onboarding.service: Service RestartSec=100ms expired, scheduling restart. Apr 12 08:36:52 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Apr 12 08:36:52 volumio systemd[1]: Stopped Volumio5 Onboarding Server. Apr 12 08:36:52 volumio systemd[1]: Started Volumio5 Onboarding Server. Apr 12 08:36:52 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:52 volumio volumio[955]: 1+1 records in Apr 12 08:36:52 volumio volumio[955]: 1+1 records out Apr 12 08:36:52 volumio volumio[955]: 62560 bytes (63 kB, 61 KiB) copied, 0.000742396 s, 84.3 MB/s Apr 12 08:36:52 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:52.978+02:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 12 08:36:53 volumio volumio[955]: 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: 10 Apr 12 08:36:53 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:53 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:53 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.073+02:00 level=INFO msg="system info for 1d09f5c2b4173ab806b46b684d6f3f0a" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=3.912 Apr 12 08:36:53 volumio volumio[955]: 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: 10 Apr 12 08:36:53 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:53 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:53 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.098+02:00 level=INFO msg="enabling local network discovery" Apr 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.185+02:00 level=INFO msg="enabling BLE discovery" Apr 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.257+02:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 12 08:36:53 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:53 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:53 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:53 volumio volumio-remote-updater[551]: No test mode Apr 12 08:36:53 volumio volumio-remote-updater[551]: No alpha test mode Apr 12 08:36:53 volumio volumio[955]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 08:36:53 volumio volumio[955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:53 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.808+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 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.809+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 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.809+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 12 08:36:53 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:53.810+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory" Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:53 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 12 08:36:54 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:54 volumio volumio[955]: 1+1 records in Apr 12 08:36:54 volumio volumio[955]: 1+1 records out Apr 12 08:36:54 volumio volumio[955]: 64688 bytes (65 kB, 63 KiB) copied, 0.000390833 s, 166 MB/s Apr 12 08:36:54 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:54 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 12 08:36:55 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:55 volumio volumio[955]: 1+1 records in Apr 12 08:36:55 volumio volumio[955]: 1+1 records out Apr 12 08:36:55 volumio volumio[955]: 63504 bytes (64 kB, 62 KiB) copied, 0.000913437 s, 69.5 MB/s Apr 12 08:36:55 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:55.213+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=P1tHyBwD2bPGwpo2Gh08P3qbHSw1 tokenExpiry=2026-04-12T09:36:55.213+02:00 Apr 12 08:36:55 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 08:36:55 volumio volumio[955]: info: Received Get System Info Apr 12 08:36:55 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:36:55 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:36:55 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:36:55 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:36:55 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:36:55 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:36:56 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:56 volumio volumio[955]: 1+1 records in Apr 12 08:36:56 volumio volumio[955]: 1+1 records out Apr 12 08:36:56 volumio volumio[955]: 64576 bytes (65 kB, 63 KiB) copied, 0.000466719 s, 138 MB/s Apr 12 08:36:57 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:57 volumio volumio[955]: 1+1 records in Apr 12 08:36:57 volumio volumio[955]: 1+1 records out Apr 12 08:36:57 volumio volumio[955]: 64704 bytes (65 kB, 63 KiB) copied, 0.000416458 s, 155 MB/s Apr 12 08:36:57 volumio volumio5-onboarding[1930]: time=2026-04-12T08:36:57.789+02:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 12 08:36:58 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:58 volumio volumio[955]: 13+1 records in Apr 12 08:36:58 volumio volumio[955]: 13+1 records out Apr 12 08:36:58 volumio volumio[955]: 455200 bytes (455 kB, 445 KiB) copied, 0.00358828 s, 127 MB/s Apr 12 08:36:58 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:36:58 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 12 08:36:58 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 12 08:36:58 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 12 08:36:58 volumio volumio[955]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 08:36:58 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:36:59 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:36:59 volumio volumio[955]: 15+1 records in Apr 12 08:36:59 volumio volumio[955]: 15+1 records out Apr 12 08:36:59 volumio volumio[955]: 521008 bytes (521 kB, 509 KiB) copied, 0.00415953 s, 125 MB/s Apr 12 08:37:00 volumio volumio[955]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 12 08:37:00 volumio volumio[955]: info: Completed starting MyVolumio Plugin Apr 12 08:37:00 volumio volumio[955]: [Metrics] CommandRouter: 53s 811.01ms Apr 12 08:37:00 volumio volumio[955]: info: CoreCommandRouter::volumiosetStartupVolume Apr 12 08:37:00 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 08:37:00 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 08:37:00 volumio volumio[955]: info: CoreCommandRouter::Close All Modals sent Apr 12 08:37:00 volumio volumio[955]: info: CoreCommandRouter::Close All Modals sent Apr 12 08:37:00 volumio volumio[955]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Apr 12 08:37:00 volumio volumio[955]: info: FusionDsp - ---- read samplerate from file: 44100 Apr 12 08:37:00 volumio volumio[955]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 12 08:37:00 volumio volumio[955]: error: FusionDsp - WebSocket error: [object Object] Apr 12 08:37:00 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:00 volumio volumio[955]: 3+22 records in Apr 12 08:37:00 volumio volumio[955]: 3+22 records out Apr 12 08:37:00 volumio volumio[955]: 189680 bytes (190 kB, 185 KiB) copied, 0.00065125 s, 291 MB/s Apr 12 08:37:00 volumio volumio[1428]: ......................................................................................................................++++ Apr 12 08:37:00 volumio volumio[1428]: e is 65537 (0x010001) Apr 12 08:37:00 volumio volumio[1428]: writing RSA key Apr 12 08:37:01 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 12 08:37:01 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 12 08:37:01 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 12 08:37:01 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:01 volumio volumio[955]: 5+1 records in Apr 12 08:37:01 volumio volumio[955]: 5+1 records out Apr 12 08:37:01 volumio volumio[955]: 195888 bytes (196 kB, 191 KiB) copied, 0.00161745 s, 121 MB/s Apr 12 08:37:02 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:02 volumio volumio[955]: 2+0 records in Apr 12 08:37:02 volumio volumio[955]: 2+0 records out Apr 12 08:37:02 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000397239 s, 165 MB/s Apr 12 08:37:03 volumio ntpd[803]: Soliciting pool server 82.64.141.144 Apr 12 08:37:03 volumio volumio[955]: info: VolumeController::SetAlsaVolume5 Apr 12 08:37:03 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:03 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:03 volumio volumio[955]: info: [ASDebug] CurState: play PrevState: stop Apr 12 08:37:03 volumio volumio[955]: info: [ASDebug] Togle GPIO: ON Apr 12 08:37:03 volumio volumio[955]: info: VolumeController::SetAlsaVolume15 Apr 12 08:37:03 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:03 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:03 volumio volumio[955]: info: [ASDebug] CurState: play PrevState: play Apr 12 08:37:03 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:03 volumio volumio[955]: 1+2 records in Apr 12 08:37:03 volumio volumio[955]: 1+2 records out Apr 12 08:37:03 volumio volumio[955]: 65808 bytes (66 kB, 64 KiB) copied, 0.000427291 s, 154 MB/s Apr 12 08:37:03 volumio volumio[955]: info: VolumeController::SetAlsaVolume20 Apr 12 08:37:03 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:03 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:03 volumio volumio[955]: info: [ASDebug] CurState: play PrevState: play Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 08:37:03 volumio volumio[955]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 12 08:37:03 volumio volumio[955]: info: Received Get System Version Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 08:37:03 volumio volumio[955]: info: Received Get System Info Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 08:37:03 volumio volumio[955]: info: Discovery: Getting this device information Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:37:03 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:03 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 08:37:04 volumio volumio[955]: info: VolumeController::SetAlsaVolume25 Apr 12 08:37:04 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:04 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:04 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:04 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:04 volumio volumio[955]: info: [ASDebug] CurState: play PrevState: play Apr 12 08:37:04 volumio ntpd[803]: Soliciting pool server 82.64.81.218 Apr 12 08:37:04 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:04 volumio volumio[955]: 2+0 records in Apr 12 08:37:04 volumio volumio[955]: 2+0 records out Apr 12 08:37:04 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000439896 s, 149 MB/s Apr 12 08:37:04 volumio volumio[955]: info: VolumeController::SetAlsaVolume30 Apr 12 08:37:04 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:04 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:04 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:04 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:04 volumio volumio[955]: info: [ASDebug] CurState: play PrevState: play Apr 12 08:37:05 volumio volumio[955]: info: VolumeController::SetAlsaVolume35 Apr 12 08:37:05 volumio ntpd[803]: Soliciting pool server 82.66.53.60 Apr 12 08:37:05 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:05 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:05 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:05 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:05 volumio ntpd[803]: Soliciting pool server 54.38.114.34 Apr 12 08:37:05 volumio volumio[955]: info: [ASDebug] CurState: play PrevState: play Apr 12 08:37:05 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:05 volumio volumio[955]: 1+1 records in Apr 12 08:37:05 volumio volumio[955]: 1+1 records out Apr 12 08:37:05 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000434895 s, 142 MB/s Apr 12 08:37:06 volumio ntpd[803]: Soliciting pool server 82.66.40.79 Apr 12 08:37:06 volumio ntpd[803]: Soliciting pool server 82.64.173.137 Apr 12 08:37:06 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:06 volumio volumio[955]: 2+1 records in Apr 12 08:37:06 volumio volumio[955]: 2+1 records out Apr 12 08:37:06 volumio volumio[955]: 69632 bytes (70 kB, 68 KiB) copied, 0.000442552 s, 157 MB/s Apr 12 08:37:07 volumio volumio[955]: info: BOOT COMPLETED Apr 12 08:37:07 volumio ntpd[803]: Soliciting pool server 37.59.63.125 Apr 12 08:37:07 volumio ntpd[803]: Soliciting pool server 172.233.248.179 Apr 12 08:37:07 volumio volumio[955]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Apr 12 08:37:07 volumio volumio[955]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::volumioGetState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::volumioPause Apr 12 08:37:07 volumio volumio[955]: info: CoreStateMachine::pause Apr 12 08:37:07 volumio volumio[955]: info: CoreStateMachine::stPlaybackTimer Apr 12 08:37:07 volumio volumio[955]: info: CoreStateMachine::servicePause Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePause Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand pause Apr 12 08:37:07 volumio volumio[955]: info: mpdhttpout --- Volumio set on pause Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand pause took 4 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: verbose: STATE SERVICE {"status":"pause","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music115/v4/6b/80/82/6b808262-1f95-a926-3d2d-ac71fc0b675a/source/600x600bb.jpg","name":"Nirvana - About a Girl","title":"About a Girl","artist":"90s90s Grunge","album":"","streaming":true,"disableUiControls":true,"duration":"176","seek":24945,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Apr 12 08:37:07 volumio volumio[955]: verbose: CURRENT POSITION 0 Apr 12 08:37:07 volumio volumio[955]: info: CoreStateMachine::syncState stateService pause Apr 12 08:37:07 volumio volumio[955]: info: CoreStateMachine::syncState currentStatus pause Apr 12 08:37:07 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:07 volumio volumio[955]: info: Apr 12 08:37:07 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:37:07 volumio volumio[955]: info: Apr 12 08:37:07 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:37:07 volumio volumio[955]: info: Apr 12 08:37:07 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:37:07 volumio volumio[955]: info: Apr 12 08:37:07 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:37:07 volumio volumio[955]: info: Apr 12 08:37:07 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:37:07 volumio volumio[955]: info: Apr 12 08:37:07 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:37:07 volumio volumio[955]: info: Apr 12 08:37:07 volumio volumio[955]: ---------------------------- MPD announces state update: player Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::getState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand status Apr 12 08:37:07 volumio volumio[955]: info: [ASDebug] CurState: pause PrevState: play Apr 12 08:37:07 volumio volumio[955]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand status took 39 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand status took 36 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand status took 34 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand status took 31 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand status took 32 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand status took 30 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand status took 27 milliseconds Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseState Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand playlistinfo took 12 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand playlistinfo took 12 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 12 08:37:07 volumio volumio[955]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:37:07 volumio volumio[955]: verbose: ControllerMpd::parseTrackInfo Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:37:07 volumio volumio[955]: info: ControllerMpd::pushState Apr 12 08:37:07 volumio volumio[955]: info: CoreCommandRouter::servicePushState Apr 12 08:37:07 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:07 volumio volumio[955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Apr 12 08:37:07 volumio volumio[955]: info: ------------------------------ 91ms Apr 12 08:37:07 volumio volumio[955]: info: ------------------------------ 86ms Apr 12 08:37:07 volumio volumio[955]: info: ------------------------------ 83ms Apr 12 08:37:07 volumio volumio[955]: info: ------------------------------ 81ms Apr 12 08:37:07 volumio volumio[955]: info: ------------------------------ 78ms Apr 12 08:37:07 volumio volumio[955]: info: ------------------------------ 76ms Apr 12 08:37:07 volumio volumio[955]: info: ------------------------------ 73ms Apr 12 08:37:07 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:07 volumio volumio[955]: 2+0 records in Apr 12 08:37:07 volumio volumio[955]: 2+0 records out Apr 12 08:37:07 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000399792 s, 164 MB/s Apr 12 08:37:07 volumio volumio[955]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 12 08:37:08 volumio ntpd[803]: Soliciting pool server 162.159.200.123 Apr 12 08:37:08 volumio ntpd[803]: Soliciting pool server 51.68.44.27 Apr 12 08:37:08 volumio ntpd[803]: Soliciting pool server 129.250.35.251 Apr 12 08:37:08 volumio volumio[955]: info: [ASDebug] Togle GPIO: OFF Apr 12 08:37:08 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:08 volumio volumio[955]: 2+0 records in Apr 12 08:37:08 volumio volumio[955]: 2+0 records out Apr 12 08:37:08 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000380833 s, 172 MB/s Apr 12 08:37:09 volumio volumio[955]: info: VolumeController::SetAlsaVolume40 Apr 12 08:37:09 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:09 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:09 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:09 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:09 volumio volumio[955]: info: [ASDebug] CurState: pause PrevState: pause Apr 12 08:37:09 volumio ntpd[803]: Soliciting pool server 82.64.42.185 Apr 12 08:37:09 volumio ntpd[803]: Soliciting pool server 51.75.149.45 Apr 12 08:37:09 volumio ntpd[803]: Soliciting pool server 172.232.63.219 Apr 12 08:37:09 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Apr 12 08:37:09 volumio sudo[2349]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 08:37:09 volumio sudo[2349]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:37:09 volumio systemd[1]: Stopping Music Player Daemon... Apr 12 08:37:09 volumio volumio[955]: error: Upnp client error: Error: This socket has been ended by the other party Apr 12 08:37:09 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:09 volumio volumio[955]: 1+1 records in Apr 12 08:37:09 volumio volumio[955]: 1+1 records out Apr 12 08:37:09 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000433334 s, 142 MB/s Apr 12 08:37:10 volumio ntpd[803]: Soliciting pool server 31.58.102.164 Apr 12 08:37:10 volumio ntpd[803]: Soliciting pool server 109.190.177.200 Apr 12 08:37:10 volumio ntpd[803]: Soliciting pool server 109.190.177.203 Apr 12 08:37:10 volumio systemd[1]: mpd.service: Succeeded. Apr 12 08:37:10 volumio systemd[1]: Stopped Music Player Daemon. Apr 12 08:37:10 volumio systemd[1]: Starting Music Player Daemon... Apr 12 08:37:10 volumio sudo[2356]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 08:37:10 volumio sudo[2356]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 08:37:10 volumio sudo[2356]: pam_unix(sudo:session): session closed for user root Apr 12 08:37:10 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:10 volumio volumio[955]: 2+0 records in Apr 12 08:37:10 volumio volumio[955]: 2+0 records out Apr 12 08:37:10 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.00119672 s, 54.8 MB/s Apr 12 08:37:12 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:12 volumio volumio[955]: 2+0 records in Apr 12 08:37:12 volumio volumio[955]: 2+0 records out Apr 12 08:37:12 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000667916 s, 98.1 MB/s Apr 12 08:37:13 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed85bc18.44cdc18d does not match aorg 0000000000.00000000 from server@82.66.53.60 xmt 0xed85bc19.0ac87dde Apr 12 08:37:13 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed85bc18.44ca14be does not match aorg 0000000000.00000000 from server@37.59.63.125 xmt 0xed85bc19.0b0a2170 Apr 12 08:37:13 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed85bc18.44b3d8ee does not match aorg 0000000000.00000000 from server@109.190.177.203 xmt 0xed85bc19.0aa763ae Apr 12 08:37:13 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed85bc18.44d05b10 does not match aorg 0000000000.00000000 from server@82.64.81.218 xmt 0xed85bc19.0c45fd02 Apr 12 08:37:13 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed85bc18.44d2fde8 does not match aorg 0000000000.00000000 from server@82.64.141.144 xmt 0xed85bc19.0c55501c Apr 12 08:37:13 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:13 volumio volumio[955]: 1+1 records in Apr 12 08:37:13 volumio volumio[955]: 1+1 records out Apr 12 08:37:13 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000368489 s, 167 MB/s Apr 12 08:37:14 volumio mpd[2358]: Apr 12 08:37 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 12 08:37:14 volumio systemd[1]: Started Music Player Daemon. Apr 12 08:37:14 volumio sudo[2349]: pam_unix(sudo:session): session closed for user root Apr 12 08:37:14 volumio volumio[955]: error: updateQueue error: null Apr 12 08:37:14 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:14 volumio volumio[955]: 2+0 records in Apr 12 08:37:14 volumio volumio[955]: 2+0 records out Apr 12 08:37:14 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000343281 s, 191 MB/s Apr 12 08:37:15 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:15 volumio volumio[955]: 1+1 records in Apr 12 08:37:15 volumio volumio[955]: 1+1 records out Apr 12 08:37:15 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000351197 s, 176 MB/s Apr 12 08:37:16 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:16 volumio volumio[955]: 2+0 records in Apr 12 08:37:16 volumio volumio[955]: 2+0 records out Apr 12 08:37:16 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000356875 s, 184 MB/s Apr 12 08:37:18 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:18 volumio volumio[955]: 2+0 records in Apr 12 08:37:18 volumio volumio[955]: 2+0 records out Apr 12 08:37:18 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000359115 s, 182 MB/s Apr 12 08:37:19 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:19 volumio volumio[955]: 1+1 records in Apr 12 08:37:19 volumio volumio[955]: 1+1 records out Apr 12 08:37:19 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000366406 s, 168 MB/s Apr 12 08:37:20 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:20 volumio volumio[955]: 2+0 records in Apr 12 08:37:20 volumio volumio[955]: 2+0 records out Apr 12 08:37:20 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000352657 s, 186 MB/s Apr 12 08:37:21 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:21 volumio volumio[955]: 2+0 records in Apr 12 08:37:21 volumio volumio[955]: 2+0 records out Apr 12 08:37:21 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.0003525 s, 186 MB/s Apr 12 08:37:22 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:22 volumio volumio[955]: 1+1 records in Apr 12 08:37:22 volumio volumio[955]: 1+1 records out Apr 12 08:37:22 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000362344 s, 170 MB/s Apr 12 08:37:23 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:23 volumio volumio[955]: 2+0 records in Apr 12 08:37:23 volumio volumio[955]: 2+0 records out Apr 12 08:37:23 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000371302 s, 177 MB/s Apr 12 08:37:24 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:24 volumio volumio[955]: 2+0 records in Apr 12 08:37:24 volumio volumio[955]: 2+0 records out Apr 12 08:37:24 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000361771 s, 181 MB/s Apr 12 08:37:25 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:25 volumio volumio[955]: 1+1 records in Apr 12 08:37:25 volumio volumio[955]: 1+1 records out Apr 12 08:37:25 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000371511 s, 166 MB/s Apr 12 08:37:26 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:26 volumio volumio[955]: 2+0 records in Apr 12 08:37:26 volumio volumio[955]: 2+0 records out Apr 12 08:37:26 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000350104 s, 187 MB/s Apr 12 08:37:27 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:27 volumio volumio[955]: 1+1 records in Apr 12 08:37:27 volumio volumio[955]: 1+1 records out Apr 12 08:37:27 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000335156 s, 184 MB/s Apr 12 08:37:28 volumio volumio[955]: info: CoreCommandRouter::volumioPlay Apr 12 08:37:28 volumio volumio[955]: info: CoreStateMachine::play index undefined Apr 12 08:37:28 volumio volumio[955]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 08:37:28 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:28 volumio volumio[955]: info: CoreStateMachine::startPlaybackTimer Apr 12 08:37:28 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:28 volumio volumio[955]: verbose: MPD COMMAND [object Object] Apr 12 08:37:28 volumio volumio[955]: verbose: MPD COMMAND [object Object] Apr 12 08:37:28 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:28 volumio volumio[955]: 2+0 records in Apr 12 08:37:28 volumio volumio[955]: 2+0 records out Apr 12 08:37:28 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000440521 s, 149 MB/s Apr 12 08:37:29 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:29 volumio volumio[955]: 2+0 records in Apr 12 08:37:29 volumio volumio[955]: 2+0 records out Apr 12 08:37:29 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000355625 s, 184 MB/s Apr 12 08:37:30 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:30 volumio volumio[955]: 1+1 records in Apr 12 08:37:30 volumio volumio[955]: 1+1 records out Apr 12 08:37:30 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.000350937 s, 176 MB/s Apr 12 08:37:31 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:31 volumio volumio[955]: 2+0 records in Apr 12 08:37:31 volumio volumio[955]: 2+0 records out Apr 12 08:37:31 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000346406 s, 189 MB/s Apr 12 08:37:32 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:32 volumio volumio[955]: 2+0 records in Apr 12 08:37:32 volumio volumio[955]: 2+0 records out Apr 12 08:37:32 volumio volumio[955]: 65536 bytes (66 kB, 64 KiB) copied, 0.000361562 s, 181 MB/s Apr 12 08:37:33 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:33 volumio volumio[955]: 1+1 records in Apr 12 08:37:33 volumio volumio[955]: 1+1 records out Apr 12 08:37:33 volumio volumio[955]: 61712 bytes (62 kB, 60 KiB) copied, 0.00035151 s, 176 MB/s Apr 12 08:37:34 volumio volumio[955]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Apr 12 08:37:34 volumio volumio[955]: 1+1 records in Apr 12 08:37:34 volumio volumio[955]: 1+1 records out Apr 12 08:37:34 volumio volumio[955]: 47072 bytes (47 kB, 46 KiB) copied, 0.00029599 s, 159 MB/s Apr 12 08:37:35 volumio volumio[955]: 0+0 records in Apr 12 08:37:35 volumio volumio[955]: 0+0 records out Apr 12 08:37:35 volumio volumio[955]: 0 bytes copied, 0.00014 s, 0.0 kB/s Apr 12 08:37:36 volumio volumio[955]: 0+0 records in Apr 12 08:37:36 volumio volumio[955]: 0+0 records out Apr 12 08:37:36 volumio volumio[955]: 0 bytes copied, 0.00012323 s, 0.0 kB/s Apr 12 08:37:37 volumio volumio[955]: 0+0 records in Apr 12 08:37:37 volumio volumio[955]: 0+0 records out Apr 12 08:37:37 volumio volumio[955]: 0 bytes copied, 0.000122031 s, 0.0 kB/s Apr 12 08:37:38 volumio volumio[955]: 0+0 records in Apr 12 08:37:38 volumio volumio[955]: 0+0 records out Apr 12 08:37:38 volumio volumio[955]: 0 bytes copied, 0.000143021 s, 0.0 kB/s Apr 12 08:37:39 volumio volumio[955]: 0+0 records in Apr 12 08:37:39 volumio volumio[955]: 0+0 records out Apr 12 08:37:39 volumio volumio[955]: 0 bytes copied, 0.000122396 s, 0.0 kB/s Apr 12 08:37:41 volumio volumio[955]: 0+0 records in Apr 12 08:37:41 volumio volumio[955]: 0+0 records out Apr 12 08:37:41 volumio volumio[955]: 0 bytes copied, 0.000128646 s, 0.0 kB/s Apr 12 08:37:42 volumio volumio[955]: 0+0 records in Apr 12 08:37:42 volumio volumio[955]: 0+0 records out Apr 12 08:37:42 volumio volumio[955]: 0 bytes copied, 0.000124948 s, 0.0 kB/s Apr 12 08:37:42 volumio volumio[955]: info: CoreCommandRouter::volumioSeek Apr 12 08:37:42 volumio volumio[955]: info: CoreStateMachine::seek Apr 12 08:37:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:42 volumio volumio[955]: info: TRACKBLOCK {"service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"nineties","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music115/v4/6b/80/82/6b808262-1f95-a926-3d2d-ac71fc0b675a/source/600x600bb.jpg","uri":"http://streams.90s90s.de/grunge/mp3-192/volumio","name":"Nirvana - About a Girl","duration":"176","artist":"90s90s Grunge","album":"","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Apr 12 08:37:42 volumio volumio[955]: info: CoreStateMachine::startPlaybackTimer Apr 12 08:37:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:42 volumio volumio[955]: info: [1775975862548] [80s80s] seek to 10000 Apr 12 08:37:42 volumio volumio[955]: info: CoreStateMachine::pushState Apr 12 08:37:42 volumio volumio[955]: info: CorePlayQueue::getTrack 0 Apr 12 08:37:42 volumio volumio[955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 08:37:42 volumio volumio[955]: info: CoreCommandRouter::volumioPushState Apr 12 08:37:42 volumio volumio[955]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 08:37:42 volumio volumio[955]: Error: Failed to convert napi value String into rust type `f64` on TimelineInfo.duration Apr 12 08:37:42 volumio volumio[955]: at FerrumStreamingControlTechnology.updateStateOnPlayer (/data/plugins/user_interface/ferrum_streaming_control_technology/index.js:72:12) Apr 12 08:37:42 volumio volumio[955]: at FerrumStreamingControlTechnology.pushState (/data/plugins/user_interface/ferrum_streaming_control_technology/index.js:182:10) Apr 12 08:37:42 volumio volumio[955]: at /volumio/app/index.js:326:81 Apr 12 08:37:42 volumio volumio[955]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Apr 12 08:37:42 volumio volumio[955]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Apr 12 08:37:42 volumio volumio[955]: at CoreCommandRouter.volumioPushState (/volumio/app/index.js:324:13) Apr 12 08:37:42 volumio volumio[955]: at CoreStateMachine.pushState (/volumio/app/statemachine.js:534:22) Apr 12 08:37:42 volumio volumio[955]: at CoreStateMachine.seek (/volumio/app/statemachine.js:1147:14) Apr 12 08:37:42 volumio volumio[955]: at CoreCommandRouter.volumioSeek (/volumio/app/index.js:1446:28) Apr 12 08:37:42 volumio volumio[955]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:177:33) Apr 12 08:37:42 volumio volumio[955]: at Socket.emit (events.js:315:20) Apr 12 08:37:42 volumio volumio[955]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Apr 12 08:37:42 volumio volumio[955]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Apr 12 08:37:42 volumio volumio[955]: code: 'NumberExpected' Apr 12 08:37:42 volumio volumio[955]: } Apr 12 08:37:42 volumio volumio[955]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 08:37:43 volumio sudo[2578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-12 08:36 Apr 12 08:37:43 volumio sudo[2578]: 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"